2016-05-18 00:23:50,529 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 00:23:50,544 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BasicPipesPlatformTest, with platform: hadoop
2016-05-18 00:23:50,570 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 00:23:50,803 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 00:23:50,905 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:23:50,907 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 00:23:51,006 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 7A463C75E3954117879FDD7CBC7053D1
2016-05-18 00:23:51,240 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.190
2016-05-18 00:23:51,244 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 00:23:51,244 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 00:23:51,431 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 00:23:51,432 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:23:51,432 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:23:51,433 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleChain/simplechain"]
2016-05-18 00:23:51,433 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:23:51,433 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 2
2016-05-18 00:23:51,435 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:23:51,435 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/2)
2016-05-18 00:23:51,468 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 00:23:51,502 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 00:23:51,678 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0001
2016-05-18 00:23:51,679 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:23:51,742 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:23:51,889 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:23:51,890 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:23:51,902 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D53F96AB65884F09A78819B726C10EEA, ordinal: 0
2016-05-18 00:23:51,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:23:51,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:23:51,939 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D53F96AB65884F09A78819B726C10EEA, mem on start (mb), free: 85, total: 223, max: 672
2016-05-18 00:23:51,950 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D53F96AB65884F09A78819B726C10EEA, mem on close (mb), free: 84, total: 223, max: 672
2016-05-18 00:23:54,734 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:23:54,734 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:23:54,748 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BEC2BF770CB34189A249BB7049802999, ordinal: 1
2016-05-18 00:23:54,753 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:23:54,753 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[0, 'count']]"][5270646664/test/]
2016-05-18 00:23:54,753 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BEC2BF770CB34189A249BB7049802999, mem on start (mb), free: 82, total: 223, max: 672
2016-05-18 00:23:54,773 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BEC2BF770CB34189A249BB7049802999, mem on close (mb), free: 81, total: 223, max: 672
2016-05-18 00:23:57,734 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (2/2) ...stSimpleChain/simplechain
2016-05-18 00:23:57,803 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0002
2016-05-18 00:23:57,803 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:23:57,812 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5270646664_test_3321AC2F5FFC4DAE9B99D22327FB7F9A/part-00000
2016-05-18 00:23:57,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:23:57,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:23:57,939 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A79C6375FC504F4DB40C9B35148B582B, ordinal: 0
2016-05-18 00:23:57,940 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[0, 'count']]"][5270646664/test/]
2016-05-18 00:23:57,940 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:23:57,941 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A79C6375FC504F4DB40C9B35148B582B, mem on start (mb), free: 72, total: 318, max: 672
2016-05-18 00:23:57,944 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A79C6375FC504F4DB40C9B35148B582B, mem on close (mb), free: 72, total: 318, max: 672
2016-05-18 00:24:00,818 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:00,818 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:00,829 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C94B9DECB0F64DACA9A25EAE0986AA3B, ordinal: 1
2016-05-18 00:24:00,830 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:24:00,831 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleChain/simplechain"]
2016-05-18 00:24:00,831 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C94B9DECB0F64DACA9A25EAE0986AA3B, mem on start (mb), free: 71, total: 318, max: 672
2016-05-18 00:24:00,838 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C94B9DECB0F64DACA9A25EAE0986AA3B, mem on close (mb), free: 71, total: 318, max: 672
2016-05-18 00:24:03,823 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleChain/simplechain/_temporary
2016-05-18 00:24:03,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:12.389
2016-05-18 00:24:03,844 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testSimpleChain/simplechain
2016-05-18 00:24:03,864 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:03,865 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 00:24:03,926 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-05-18 00:24:03,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:03,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:24:03,951 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 00:24:03,954 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:24:03,954 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount/count"]
2016-05-18 00:24:03,955 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 00:24:03,956 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 00:24:03,956 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 00:24:03,957 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...splatform/testCount/count
2016-05-18 00:24:04,023 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local_0003
2016-05-18 00:24:04,024 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 00:24:04,029 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt
2016-05-18 00:24:04,144 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:04,146 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:04,157 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BBD679A295244143B278BAC5993BC879, ordinal: 0
2016-05-18 00:24:04,157 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:24:04,158 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:24:04,158 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBD679A295244143B278BAC5993BC879, mem on start (mb), free: 115, total: 414, max: 672
2016-05-18 00:24:04,161 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBD679A295244143B278BAC5993BC879, mem on close (mb), free: 115, total: 414, max: 672
2016-05-18 00:24:07,035 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:07,035 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:07,044 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D874A433447D454B8F12B80B0DACF46E, ordinal: 1
2016-05-18 00:24:07,044 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:24:07,045 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount/count"]
2016-05-18 00:24:07,045 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D874A433447D454B8F12B80B0DACF46E, mem on start (mb), free: 114, total: 414, max: 672
2016-05-18 00:24:07,053 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D874A433447D454B8F12B80B0DACF46E, mem on close (mb), free: 114, total: 414, max: 672
2016-05-18 00:24:10,041 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount/count/_temporary
2016-05-18 00:24:10,041 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:06.089
2016-05-18 00:24:10,073 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testCount/count
2016-05-18 00:24:10,088 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:10,089 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 00:24:10,126 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 00:24:10,128 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:24:10,128 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 00:24:10,140 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:10,140 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:10,140 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSwap/swap"]
2016-05-18 00:24:10,141 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:10,141 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:10,141 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:10,142 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...pesplatform/testSwap/swap
2016-05-18 00:24:10,187 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0004
2016-05-18 00:24:10,189 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:10,193 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:24:10,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:10,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:10,207 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AD40D6CA94094EC48C7D2A91CCA2F681, ordinal: 0
2016-05-18 00:24:10,208 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:10,209 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSwap/swap"]
2016-05-18 00:24:10,209 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD40D6CA94094EC48C7D2A91CCA2F681, mem on start (mb), free: 103, total: 414, max: 672
2016-05-18 00:24:10,212 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD40D6CA94094EC48C7D2A91CCA2F681, mem on close (mb), free: 103, total: 414, max: 672
2016-05-18 00:24:13,204 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSwap/swap/_temporary
2016-05-18 00:24:13,205 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:03.064
2016-05-18 00:24:13,215 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testSwap/swap
2016-05-18 00:24:13,227 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:13,227 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 00:24:13,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-05-18 00:24:13,274 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:24:13,274 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 00:24:13,293 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:13,293 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 00:24:13,293 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testUnGroup/ungrouped"]
2016-05-18 00:24:13,298 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:13,298 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:13,298 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:13,299 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...orm/testUnGroup/ungrouped
2016-05-18 00:24:13,337 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0005
2016-05-18 00:24:13,342 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:13,349 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower+upper.txt
2016-05-18 00:24:13,354 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:13,354 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:13,363 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D4B19B4A5AA34274BF76AF0BAEB89A5E, ordinal: 0
2016-05-18 00:24:13,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 00:24:13,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testUnGroup/ungrouped"]
2016-05-18 00:24:13,365 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D4B19B4A5AA34274BF76AF0BAEB89A5E, mem on start (mb), free: 93, total: 414, max: 672
2016-05-18 00:24:13,366 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D4B19B4A5AA34274BF76AF0BAEB89A5E, mem on close (mb), free: 93, total: 414, max: 672
2016-05-18 00:24:16,359 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testUnGroup/ungrouped/_temporary
2016-05-18 00:24:16,360 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:03.067
2016-05-18 00:24:16,369 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testUnGroup/ungrouped
2016-05-18 00:24:16,382 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:16,383 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 00:24:16,443 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-05-18 00:24:16,444 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:16,445 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 00:24:16,471 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 00:24:16,471 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt"]
2016-05-18 00:24:16,471 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:16,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-05-18 00:24:16,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 00:24:16,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 00:24:16,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 00:24:16,474 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...lexcogrouprelativeunknown
2016-05-18 00:24:16,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local_0006
2016-05-18 00:24:16,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 00:24:16,516 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt
2016-05-18 00:24:16,611 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:16,611 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:16,619 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D2F1E0489B6949D093DA6B2C4F4FEB2A, ordinal: 0
2016-05-18 00:24:16,620 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:16,621 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-05-18 00:24:16,621 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2F1E0489B6949D093DA6B2C4F4FEB2A, mem on start (mb), free: 78, total: 509, max: 672
2016-05-18 00:24:16,623 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2F1E0489B6949D093DA6B2C4F4FEB2A, mem on close (mb), free: 78, total: 509, max: 672
2016-05-18 00:24:19,519 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt
2016-05-18 00:24:19,612 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:19,612 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:19,620 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D2F1E0489B6949D093DA6B2C4F4FEB2A, ordinal: 0
2016-05-18 00:24:19,621 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt"]
2016-05-18 00:24:19,622 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-05-18 00:24:19,622 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2F1E0489B6949D093DA6B2C4F4FEB2A, mem on start (mb), free: 39, total: 572, max: 672
2016-05-18 00:24:19,624 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2F1E0489B6949D093DA6B2C4F4FEB2A, mem on close (mb), free: 39, total: 572, max: 672
2016-05-18 00:24:22,528 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:22,528 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:22,536 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B12660A252744D7FA20A5EA0C4237839, ordinal: 1
2016-05-18 00:24:22,537 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-05-18 00:24:22,538 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-05-18 00:24:22,538 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B12660A252744D7FA20A5EA0C4237839, mem on start (mb), free: 38, total: 572, max: 672
2016-05-18 00:24:22,551 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:24:22,552 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:24:22,558 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B12660A252744D7FA20A5EA0C4237839, mem on close (mb), free: 37, total: 572, max: 672
2016-05-18 00:24:25,534 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown/_temporary
2016-05-18 00:24:25,535 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:09.063
2016-05-18 00:24:25,554 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown
2016-05-18 00:24:25,569 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:25,570 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 00:24:25,619 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.044
2016-05-18 00:24:25,622 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:25,622 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 00:24:25,646 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:25,647 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:25,647 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-05-18 00:24:25,647 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:25,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:25,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:25,649 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...leRelative/simplerelative
2016-05-18 00:24:25,729 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0007
2016-05-18 00:24:25,729 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:25,735 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:24:25,965 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:25,965 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:25,972 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E9B26CE98FE7415AA94EBB961A6B17D3, ordinal: 0
2016-05-18 00:24:25,972 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:25,973 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:24:25,973 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E9B26CE98FE7415AA94EBB961A6B17D3, mem on start (mb), free: 140, total: 246, max: 672
2016-05-18 00:24:25,975 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E9B26CE98FE7415AA94EBB961A6B17D3, mem on close (mb), free: 140, total: 246, max: 672
2016-05-18 00:24:28,739 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:28,740 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:28,751 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B180767801C448AFA735140A17B68697, ordinal: 1
2016-05-18 00:24:28,752 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:24:28,752 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-05-18 00:24:28,752 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B180767801C448AFA735140A17B68697, mem on start (mb), free: 139, total: 246, max: 672
2016-05-18 00:24:28,758 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B180767801C448AFA735140A17B68697, mem on close (mb), free: 139, total: 246, max: 672
2016-05-18 00:24:31,747 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleRelative/simplerelative/_temporary
2016-05-18 00:24:31,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.101
2016-05-18 00:24:31,760 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testSimpleRelative/simplerelative
2016-05-18 00:24:31,949 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:31,950 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 00:24:31,995 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-05-18 00:24:31,997 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:31,997 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 00:24:32,020 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:32,021 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:32,021 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleResult/simpleresult"]
2016-05-18 00:24:32,022 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:32,022 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:32,023 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:32,023 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...SimpleResult/simpleresult
2016-05-18 00:24:32,053 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0008
2016-05-18 00:24:32,055 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:32,059 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt
2016-05-18 00:24:32,155 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:32,156 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:32,163 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B8EDA157B8AB40A1A1A7923A0175C7A2, ordinal: 0
2016-05-18 00:24:32,164 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:32,165 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:24:32,165 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8EDA157B8AB40A1A1A7923A0175C7A2, mem on start (mb), free: 116, total: 342, max: 672
2016-05-18 00:24:32,246 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8EDA157B8AB40A1A1A7923A0175C7A2, mem on close (mb), free: 112, total: 342, max: 672
2016-05-18 00:24:35,063 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:35,064 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:35,071 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A5C87DC9C57D4328A61BD031322B379A, ordinal: 1
2016-05-18 00:24:35,072 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:24:35,072 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleResult/simpleresult"]
2016-05-18 00:24:35,073 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A5C87DC9C57D4328A61BD031322B379A, mem on start (mb), free: 111, total: 342, max: 672
2016-05-18 00:24:35,077 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A5C87DC9C57D4328A61BD031322B379A, mem on close (mb), free: 111, total: 342, max: 672
2016-05-18 00:24:38,068 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleResult/simpleresult/_temporary
2016-05-18 00:24:38,068 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.047
2016-05-18 00:24:38,077 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testSimpleResult/simpleresult
2016-05-18 00:24:38,085 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:38,086 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 00:24:38,116 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-18 00:24:38,117 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:24:38,117 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 00:24:38,129 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:38,129 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:38,129 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testFilterAll/filterall"]
2016-05-18 00:24:38,130 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:38,130 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:38,130 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:38,130 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFilterAll/filterall
2016-05-18 00:24:38,159 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0009
2016-05-18 00:24:38,159 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:38,163 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:24:38,166 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:38,166 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:38,173 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E0E557F691FA4792ABC752A62A3BB732, ordinal: 0
2016-05-18 00:24:38,174 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:38,175 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testFilterAll/filterall"]
2016-05-18 00:24:38,175 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E0E557F691FA4792ABC752A62A3BB732, mem on start (mb), free: 102, total: 342, max: 672
2016-05-18 00:24:38,176 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E0E557F691FA4792ABC752A62A3BB732, mem on close (mb), free: 101, total: 342, max: 672
2016-05-18 00:24:41,174 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testFilterAll/filterall/_temporary
2016-05-18 00:24:41,174 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:03.044
2016-05-18 00:24:41,182 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testFilterAll/filterall
2016-05-18 00:24:41,190 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:41,190 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 00:24:41,236 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-05-18 00:24:41,237 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:41,237 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 00:24:41,251 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:41,251 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:41,251 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-05-18 00:24:41,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:41,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:41,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:41,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...own/simplerelativeunknown
2016-05-18 00:24:41,279 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0010
2016-05-18 00:24:41,281 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:41,283 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt
2016-05-18 00:24:41,388 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:41,388 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:41,394 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D7DF614F7E7B40F28DF9581755372A11, ordinal: 0
2016-05-18 00:24:41,395 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:41,396 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:-1]]
2016-05-18 00:24:41,396 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7DF614F7E7B40F28DF9581755372A11, mem on start (mb), free: 190, total: 495, max: 672
2016-05-18 00:24:41,398 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7DF614F7E7B40F28DF9581755372A11, mem on close (mb), free: 190, total: 495, max: 672
2016-05-18 00:24:44,288 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:44,288 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:44,295 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F228ABAE699445A194DE222CDDED9427, ordinal: 1
2016-05-18 00:24:44,296 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:-1]]
2016-05-18 00:24:44,296 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-05-18 00:24:44,296 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F228ABAE699445A194DE222CDDED9427, mem on start (mb), free: 189, total: 495, max: 672
2016-05-18 00:24:44,301 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F228ABAE699445A194DE222CDDED9427, mem on close (mb), free: 189, total: 495, max: 672
2016-05-18 00:24:47,297 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown/_temporary
2016-05-18 00:24:47,297 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.045
2016-05-18 00:24:47,306 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown
2016-05-18 00:24:47,315 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:47,316 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 00:24:47,366 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.047
2016-05-18 00:24:47,367 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:47,367 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 00:24:47,393 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 00:24:47,394 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt"]
2016-05-18 00:24:47,395 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:47,396 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCoGroup/complexcogroup"]
2016-05-18 00:24:47,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 00:24:47,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 00:24:47,398 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 00:24:47,399 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...estCoGroup/complexcogroup
2016-05-18 00:24:47,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local_0011
2016-05-18 00:24:47,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 00:24:47,458 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt
2016-05-18 00:24:47,648 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:47,648 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:47,656 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EFC6BA95ACB64F6989E4D4A42E73DA52, ordinal: 0
2016-05-18 00:24:47,656 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt"]
2016-05-18 00:24:47,656 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-05-18 00:24:47,657 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EFC6BA95ACB64F6989E4D4A42E73DA52, mem on start (mb), free: 194, total: 592, max: 672
2016-05-18 00:24:47,658 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EFC6BA95ACB64F6989E4D4A42E73DA52, mem on close (mb), free: 194, total: 592, max: 672
2016-05-18 00:24:50,452 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt
2016-05-18 00:24:50,466 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:50,467 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:50,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EFC6BA95ACB64F6989E4D4A42E73DA52, ordinal: 0
2016-05-18 00:24:50,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 00:24:50,479 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-05-18 00:24:50,479 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EFC6BA95ACB64F6989E4D4A42E73DA52, mem on start (mb), free: 92, total: 592, max: 672
2016-05-18 00:24:50,481 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EFC6BA95ACB64F6989E4D4A42E73DA52, mem on close (mb), free: 92, total: 592, max: 672
2016-05-18 00:24:53,459 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:24:53,459 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:24:53,465 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A4F90F7D44824A39967F7DB0DBA1E997, ordinal: 1
2016-05-18 00:24:53,466 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-05-18 00:24:53,466 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCoGroup/complexcogroup"]
2016-05-18 00:24:53,466 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A4F90F7D44824A39967F7DB0DBA1E997, mem on start (mb), free: 91, total: 592, max: 672
2016-05-18 00:24:53,473 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:24:53,473 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:24:53,476 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A4F90F7D44824A39967F7DB0DBA1E997, mem on close (mb), free: 91, total: 592, max: 672
2016-05-18 00:24:56,460 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCoGroup/complexcogroup/_temporary
2016-05-18 00:24:56,461 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:09.067
2016-05-18 00:24:56,474 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testCoGroup/complexcogroup
2016-05-18 00:24:56,482 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:56,482 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 00:24:56,508 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 00:24:56,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:24:56,509 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 00:24:56,517 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:24:56,517 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:56,518 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testReplace/replace"]
2016-05-18 00:24:56,519 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:24:56,520 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:24:56,520 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:24:56,521 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tform/testReplace/replace
2016-05-18 00:24:56,565 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0012
2016-05-18 00:24:56,565 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:24:56,568 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:24:56,571 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:56,571 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:56,576 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A16409E06B054216B60D2A1655C76A39, ordinal: 0
2016-05-18 00:24:56,577 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:24:56,579 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testReplace/replace"]
2016-05-18 00:24:56,579 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A16409E06B054216B60D2A1655C76A39, mem on start (mb), free: 309, total: 705, max: 705
2016-05-18 00:24:56,581 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A16409E06B054216B60D2A1655C76A39, mem on close (mb), free: 309, total: 705, max: 705
2016-05-18 00:24:59,571 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testReplace/replace/_temporary
2016-05-18 00:24:59,572 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:03.054
2016-05-18 00:24:59,580 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testReplace/replace
2016-05-18 00:24:59,588 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:24:59,588 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 00:24:59,620 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 00:24:59,621 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:24:59,621 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:24:59,634 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 00:24:59,634 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:24:59,634 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount2/count2"]
2016-05-18 00:24:59,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 00:24:59,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 00:24:59,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 00:24:59,636 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...latform/testCount2/count2
2016-05-18 00:24:59,657 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local_0013
2016-05-18 00:24:59,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 00:24:59,663 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt
2016-05-18 00:24:59,678 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:24:59,678 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:24:59,683 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D7ECBFB9996040AEA507EC72FAB9E349, ordinal: 0
2016-05-18 00:24:59,684 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:24:59,684 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:24:59,685 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7ECBFB9996040AEA507EC72FAB9E349, mem on start (mb), free: 197, total: 705, max: 705
2016-05-18 00:24:59,688 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7ECBFB9996040AEA507EC72FAB9E349, mem on close (mb), free: 197, total: 705, max: 705
2016-05-18 00:25:02,667 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:02,667 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:02,673 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B4989AD3A98140F887BBA6CD7E779A2B, ordinal: 1
2016-05-18 00:25:02,673 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:25:02,673 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount2/count2"]
2016-05-18 00:25:02,674 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B4989AD3A98140F887BBA6CD7E779A2B, mem on start (mb), free: 195, total: 705, max: 705
2016-05-18 00:25:02,680 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B4989AD3A98140F887BBA6CD7E779A2B, mem on close (mb), free: 195, total: 705, max: 705
2016-05-18 00:25:05,670 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount2/count2/_temporary
2016-05-18 00:25:05,671 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:06.036
2016-05-18 00:25:05,685 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testCount2/count2
2016-05-18 00:25:05,693 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:25:05,693 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 00:25:05,725 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-18 00:25:05,726 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:25:05,726 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:25:05,746 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 00:25:05,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:25:05,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount3/count3"]
2016-05-18 00:25:05,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 00:25:05,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 00:25:05,749 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 00:25:05,750 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...latform/testCount3/count3
2016-05-18 00:25:05,786 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local_0014
2016-05-18 00:25:05,787 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 00:25:05,792 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt
2016-05-18 00:25:06,173 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:06,173 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:06,180 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DF175ED471824B279DB17A3102F3D17D, ordinal: 0
2016-05-18 00:25:06,181 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:25:06,182 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:25:06,182 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF175ED471824B279DB17A3102F3D17D, mem on start (mb), free: 391, total: 499, max: 672
2016-05-18 00:25:06,186 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF175ED471824B279DB17A3102F3D17D, mem on close (mb), free: 391, total: 499, max: 672
2016-05-18 00:25:08,795 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:08,796 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:08,800 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CE944FF746764A74A314292F59825D5A, ordinal: 1
2016-05-18 00:25:08,801 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:25:08,801 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount3/count3"]
2016-05-18 00:25:08,801 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CE944FF746764A74A314292F59825D5A, mem on start (mb), free: 389, total: 499, max: 672
2016-05-18 00:25:08,807 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CE944FF746764A74A314292F59825D5A, mem on close (mb), free: 389, total: 499, max: 672
2016-05-18 00:25:11,806 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount3/count3/_temporary
2016-05-18 00:25:11,807 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:06.060
2016-05-18 00:25:11,820 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testCount3/count3
2016-05-18 00:25:11,828 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:25:11,829 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 00:25:11,862 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 00:25:11,863 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:25:11,863 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:25:11,875 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 00:25:11,875 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:25:11,875 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount4/count4"]
2016-05-18 00:25:11,876 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 00:25:11,876 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 00:25:11,876 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 00:25:11,878 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...latform/testCount4/count4
2016-05-18 00:25:11,900 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local_0015
2016-05-18 00:25:11,900 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 00:25:11,904 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt
2016-05-18 00:25:11,918 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:11,918 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:11,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CB7A58AEE1B245ACB4B753F98B7F9A02, ordinal: 0
2016-05-18 00:25:11,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:25:11,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:25:11,925 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CB7A58AEE1B245ACB4B753F98B7F9A02, mem on start (mb), free: 276, total: 499, max: 672
2016-05-18 00:25:11,927 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CB7A58AEE1B245ACB4B753F98B7F9A02, mem on close (mb), free: 276, total: 499, max: 672
2016-05-18 00:25:14,908 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:14,908 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:14,912 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FD5B69571B7444248B85B4328C0438E2, ordinal: 1
2016-05-18 00:25:14,913 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 00:25:14,913 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount4/count4"]
2016-05-18 00:25:14,913 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FD5B69571B7444248B85B4328C0438E2, mem on start (mb), free: 274, total: 499, max: 672
2016-05-18 00:25:14,919 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FD5B69571B7444248B85B4328C0438E2, mem on close (mb), free: 274, total: 499, max: 672
2016-05-18 00:25:17,911 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testCount4/count4/_temporary
2016-05-18 00:25:17,912 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:06.036
2016-05-18 00:25:17,928 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testCount4/count4
2016-05-18 00:25:17,938 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:25:17,938 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 00:25:17,959 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-05-18 00:25:17,959 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:25:17,960 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 00:25:17,967 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:25:17,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:25:17,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testFilter/filter"]
2016-05-18 00:25:17,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:25:17,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:25:17,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:25:17,969 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...latform/testFilter/filter
2016-05-18 00:25:17,991 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0016
2016-05-18 00:25:17,991 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:25:17,995 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:25:17,998 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:17,998 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:18,004 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A34F670183FD4FF5AF0983E3577A5C21, ordinal: 0
2016-05-18 00:25:18,004 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:25:18,005 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testFilter/filter"]
2016-05-18 00:25:18,005 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A34F670183FD4FF5AF0983E3577A5C21, mem on start (mb), free: 259, total: 499, max: 672
2016-05-18 00:25:18,007 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A34F670183FD4FF5AF0983E3577A5C21, mem on close (mb), free: 259, total: 499, max: 672
2016-05-18 00:25:21,005 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testFilter/filter/_temporary
2016-05-18 00:25:21,006 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:03.038
2016-05-18 00:25:21,013 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testFilter/filter
2016-05-18 00:25:21,022 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:25:21,023 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 00:25:21,053 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-18 00:25:21,054 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 00:25:21,054 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 00:25:21,069 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 00:25:21,069 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:25:21,069 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimple/simple"]
2016-05-18 00:25:21,070 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 00:25:21,070 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 00:25:21,070 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 00:25:21,070 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...latform/testSimple/simple
2016-05-18 00:25:21,091 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0017
2016-05-18 00:25:21,092 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 00:25:21,096 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 00:25:21,117 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:21,117 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:21,122 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AF65517A06194B3CB79A988EE2A15C90, ordinal: 0
2016-05-18 00:25:21,123 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 00:25:21,123 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:25:21,123 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AF65517A06194B3CB79A988EE2A15C90, mem on start (mb), free: 291, total: 499, max: 672
2016-05-18 00:25:21,125 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AF65517A06194B3CB79A988EE2A15C90, mem on close (mb), free: 291, total: 499, max: 672
2016-05-18 00:25:24,101 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:24,101 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:24,106 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BA0B4A4A2E614E1ABD164B0B3BDCD146, ordinal: 1
2016-05-18 00:25:24,107 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 00:25:24,107 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimple/simple"]
2016-05-18 00:25:24,107 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BA0B4A4A2E614E1ABD164B0B3BDCD146, mem on start (mb), free: 288, total: 499, max: 672
2016-05-18 00:25:24,112 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BA0B4A4A2E614E1ABD164B0B3BDCD146, mem on close (mb), free: 288, total: 499, max: 672
2016-05-18 00:25:27,111 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/basicpipesplatform/testSimple/simple/_temporary
2016-05-18 00:25:27,112 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.042
2016-05-18 00:25:27,119 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/basicpipesplatform/testSimple/simple