2016-05-18 05:03:23,766 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 05:03:23,783 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.RegressionPipesPlatformTest, with platform: hadoop
2016-05-18 05:03:23,808 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 05:03:24,032 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 05:03:24,137 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:24,139 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:24,237 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 71798EA335A547EEB39D70DC809E3378
2016-05-18 05:03:24,394 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.114
2016-05-18 05:03:24,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:24,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:24,556 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 05:03:24,557 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:24,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:03:24,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-18 05:03:24,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:24,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:24,561 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:24,562 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...regression/complexlogicor
2016-05-18 05:03:24,609 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 05:03:24,673 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 05:03:24,903 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local289092826_0001
2016-05-18 05:03:24,904 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:25,023 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:03:25,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:25,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:25,060 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E704719D926241169E735347EDC84140, ordinal: 0
2016-05-18 05:03:25,096 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:03:25,097 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-18 05:03:25,098 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E704719D926241169E735347EDC84140, mem on start (mb), free: 184, total: 223, max: 672
2016-05-18 05:03:25,112 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E704719D926241169E735347EDC84140, mem on close (mb), free: 184, total: 223, max: 672
2016-05-18 05:03:25,140 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor/_temporary
2016-05-18 05:03:25,141 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.581
2016-05-18 05:03:25,162 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor
2016-05-18 05:03:25,184 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:25,184 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:25,234 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.044
2016-05-18 05:03:25,236 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:25,236 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:25,251 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-18 05:03:25,251 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:03:25,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 05:03:25,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] parallel execution of steps is enabled: false
2016-05-18 05:03:25,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executing total steps: 1
2016-05-18 05:03:25,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] allocating management threads: 1
2016-05-18 05:03:25,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...oupSplitPipe/intermediate
2016-05-18 05:03:25,342 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local1868912950_0002
2016-05-18 05:03:25,342 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-18 05:03:25,347 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt
2016-05-18 05:03:25,352 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:25,352 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:25,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FDC671C88FA54EDC95117B445643B3ED, ordinal: 0
2016-05-18 05:03:25,365 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:03:25,366 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 05:03:25,366 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FDC671C88FA54EDC95117B445643B3ED, mem on start (mb), free: 171, total: 223, max: 672
2016-05-18 05:03:25,368 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FDC671C88FA54EDC95117B445643B3ED, mem on close (mb), free: 171, total: 223, max: 672
2016-05-18 05:03:25,384 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate/_temporary
2016-05-18 05:03:25,385 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] completed in: 00:00.133
2016-05-18 05:03:25,408 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:25,408 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:25,494 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.079
2016-05-18 05:03:25,497 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:03:25,497 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:25,532 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-18 05:03:25,533 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 05:03:25,533 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-18 05:03:25,534 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] parallel execution of steps is enabled: false
2016-05-18 05:03:25,535 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executing total steps: 1
2016-05-18 05:03:25,535 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] allocating management threads: 1
2016-05-18 05:03:25,536 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...oupSplitPipe/cogroupsplit
2016-05-18 05:03:25,598 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_local635052078_0003
2016-05-18 05:03:25,599 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://localhost:8080/
2016-05-18 05:03:25,604 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate/part-00000
2016-05-18 05:03:25,768 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:25,769 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:25,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EA562AC33B564A2096EE355F6DECE4A2, ordinal: 0
2016-05-18 05:03:25,800 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 05:03:25,801 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-18 05:03:25,801 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EA562AC33B564A2096EE355F6DECE4A2, mem on start (mb), free: 112, total: 223, max: 672
2016-05-18 05:03:25,816 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EA562AC33B564A2096EE355F6DECE4A2, mem on close (mb), free: 112, total: 223, max: 672
2016-05-18 05:03:25,861 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:25,861 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:25,877 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CE15E702A249453FB5DA8519FBF5E3E3, ordinal: 1
2016-05-18 05:03:25,879 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-18 05:03:25,880 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-18 05:03:25,880 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CE15E702A249453FB5DA8519FBF5E3E3, mem on start (mb), free: 110, total: 223, max: 672
2016-05-18 05:03:25,894 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 05:03:25,894 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 05:03:25,906 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CE15E702A249453FB5DA8519FBF5E3E3, mem on close (mb), free: 109, total: 223, max: 672
2016-05-18 05:03:25,920 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit/_temporary
2016-05-18 05:03:25,920 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] completed in: 00:00.388
2016-05-18 05:03:25,943 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testCoGroupSplitPipe/intermediate
2016-05-18 05:03:25,943 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit
2016-05-18 05:03:25,954 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:25,955 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:26,006 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.047
2016-05-18 05:03:26,008 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:03:26,008 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:26,029 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:26,030 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.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-18 05:03:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:26,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...eSortUnknown/none-unknown
2016-05-18 05:03:26,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local317762855_0004
2016-05-18 05:03:26,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:26,104 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:03:26,205 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:26,206 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,215 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: ACE154139458411B8B3B1E3F028BEDFF, ordinal: 0
2016-05-18 05:03:26,216 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:26,217 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2016-05-18 05:03:26,217 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ACE154139458411B8B3B1E3F028BEDFF, mem on start (mb), free: 91, total: 318, max: 672
2016-05-18 05:03:26,219 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ACE154139458411B8B3B1E3F028BEDFF, mem on close (mb), free: 91, total: 318, max: 672
2016-05-18 05:03:26,234 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:26,234 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,244 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FA4A2C0A4BF941F2BA68E5A46ACE5AA1, ordinal: 1
2016-05-18 05:03:26,245 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2016-05-18 05:03:26,245 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.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-18 05:03:26,245 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FA4A2C0A4BF941F2BA68E5A46ACE5AA1, mem on start (mb), free: 90, total: 318, max: 672
2016-05-18 05:03:26,253 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FA4A2C0A4BF941F2BA68E5A46ACE5AA1, mem on close (mb), free: 89, total: 318, max: 672
2016-05-18 05:03:26,262 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown/_temporary
2016-05-18 05:03:26,262 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.232
2016-05-18 05:03:26,272 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown
2016-05-18 05:03:26,282 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:26,282 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:26,314 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-18 05:03:26,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:26,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:26,333 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:26,334 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-05-18 05:03:26,334 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.2.x/build/test/output/hadoop/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-18 05:03:26,334 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:26,335 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:26,335 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:26,335 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 05:03:26,372 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local624473133_0005
2016-05-18 05:03:26,372 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:26,376 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.10.txt
2016-05-18 05:03:26,380 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:26,380 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,390 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5F3C2E74B224259979976272299C9F3, ordinal: 0
2016-05-18 05:03:26,391 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-05-18 05:03:26,391 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.2.x/build/test/output/hadoop/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-18 05:03:26,392 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5F3C2E74B224259979976272299C9F3, mem on start (mb), free: 78, total: 318, max: 672
2016-05-18 05:03:26,394 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:583)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:110)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:366)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:223)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:03:26,398 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5F3C2E74B224259979976272299C9F3, mem on close (mb), free: 77, total: 318, max: 672
2016-05-18 05:03:26,399 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local624473133_0005
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:354)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:583)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:110)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:366)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:223)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:03:26,402 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] hadoop job job_local624473133_0005 state at FAILED
2016-05-18 05:03:26,403 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] failure info: NA
2016-05-18 05:03:26,404 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events identify failed tasks
2016-05-18 05:03:26,404 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events count: 0
2016-05-18 05:03:26,404 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-18 05:03:26,404 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 05:03:26,404 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-18 05:03:26,405 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testOOMEPreGroup/oomepre/_temporary
2016-05-18 05:03:26,405 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.071
exception = cascading.flow.FlowException: local step failed: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 05:03:26,406 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testOOMEPreGroup/oomepre
2016-05-18 05:03:26,415 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:26,416 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:26,445 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-18 05:03:26,446 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:26,446 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:26,455 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:26,455 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:26,455 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.2.x/build/test/output/hadoop/regressionpipesplatform/testCopy/copy"]
2016-05-18 05:03:26,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:26,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:26,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:26,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...pesplatform/testCopy/copy
2016-05-18 05:03:26,496 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1462432189_0006
2016-05-18 05:03:26,496 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:26,500 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:03:26,504 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:26,505 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,511 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DC63735C7BB14593A8F23DA9543BC306, ordinal: 0
2016-05-18 05:03:26,512 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:26,512 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.2.x/build/test/output/hadoop/regressionpipesplatform/testCopy/copy"]
2016-05-18 05:03:26,513 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DC63735C7BB14593A8F23DA9543BC306, mem on start (mb), free: 68, total: 318, max: 672
2016-05-18 05:03:26,514 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DC63735C7BB14593A8F23DA9543BC306, mem on close (mb), free: 68, total: 318, max: 672
2016-05-18 05:03:26,527 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testCopy/copy/_temporary
2016-05-18 05:03:26,528 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.072
2016-05-18 05:03:26,536 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testCopy/copy
2016-05-18 05:03:26,550 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:26,551 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:26,585 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 05:03:26,586 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:26,586 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-18 05:03:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:26,601 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...wnReplace/unknown-replace
2016-05-18 05:03:26,662 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local215468957_0007
2016-05-18 05:03:26,662 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:26,667 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:03:26,672 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:26,672 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,680 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AD9EA5A305054A8E9384802D25BAB1B6, ordinal: 0
2016-05-18 05:03:26,681 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:26,681 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-18 05:03:26,681 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD9EA5A305054A8E9384802D25BAB1B6, mem on start (mb), free: 118, total: 318, max: 672
2016-05-18 05:03:26,683 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD9EA5A305054A8E9384802D25BAB1B6, mem on close (mb), free: 118, total: 318, max: 672
2016-05-18 05:03:26,693 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testUnknownReplace/unknown-replace/_temporary
2016-05-18 05:03:26,694 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.093
2016-05-18 05:03:26,713 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testUnknownReplace/unknown-replace
2016-05-18 05:03:26,723 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:26,724 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:26,766 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-05-18 05:03:26,767 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:26,768 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:26,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:26,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:03:26,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-18 05:03:26,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:26,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:26,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:26,784 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicand
2016-05-18 05:03:26,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1744857764_0008
2016-05-18 05:03:26,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:26,830 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:03:26,836 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:26,836 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,848 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E8FA2F2197A64813B7B8FCDCE954014B, ordinal: 0
2016-05-18 05:03:26,849 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:03:26,849 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-18 05:03:26,850 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E8FA2F2197A64813B7B8FCDCE954014B, mem on start (mb), free: 104, total: 318, max: 672
2016-05-18 05:03:26,852 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E8FA2F2197A64813B7B8FCDCE954014B, mem on close (mb), free: 104, total: 318, max: 672
2016-05-18 05:03:26,866 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand/_temporary
2016-05-18 05:03:26,867 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.084
2016-05-18 05:03:26,879 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand
2016-05-18 05:03:26,889 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:26,890 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:26,926 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 05:03:26,927 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:26,927 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:26,945 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:26,946 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:03:26,946 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-18 05:03:26,946 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:26,948 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:26,948 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:26,949 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicxor
2016-05-18 05:03:26,976 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1773822525_0009
2016-05-18 05:03:26,977 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:26,982 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:03:26,986 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:26,986 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:26,994 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EAFFF66B2AA548729C12C4AD993360AE, ordinal: 0
2016-05-18 05:03:26,995 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:03:26,995 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-18 05:03:26,995 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EAFFF66B2AA548729C12C4AD993360AE, mem on start (mb), free: 93, total: 318, max: 672
2016-05-18 05:03:26,997 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EAFFF66B2AA548729C12C4AD993360AE, mem on close (mb), free: 92, total: 318, max: 672
2016-05-18 05:03:27,012 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor/_temporary
2016-05-18 05:03:27,012 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.066
2016-05-18 05:03:27,020 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor
2016-05-18 05:03:27,030 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:27,031 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:27,101 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.067
2016-05-18 05:03:27,102 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:03:27,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:27,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 05:03:27,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-05-18 05:03:27,125 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:03:27,125 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-18 05:03:27,126 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 05:03:27,127 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 05:03:27,127 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 05:03:27,128 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 05:03:27,164 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local1464117486_0010
2016-05-18 05:03:27,164 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 05:03:27,170 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/upper.txt
2016-05-18 05:03:27,272 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:27,272 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,281 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A46BFDADA89F4C5F84FB59A255778006, ordinal: 0
2016-05-18 05:03:27,281 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-05-18 05:03:27,282 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 05:03:27,282 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A46BFDADA89F4C5F84FB59A255778006, mem on start (mb), free: 75, total: 414, max: 672
2016-05-18 05:03:27,284 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A46BFDADA89F4C5F84FB59A255778006, mem on close (mb), free: 75, total: 414, max: 672
2016-05-18 05:03:27,292 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt
2016-05-18 05:03:27,393 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:27,393 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,401 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A46BFDADA89F4C5F84FB59A255778006, ordinal: 0
2016-05-18 05:03:27,402 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:03:27,403 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 05:03:27,403 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A46BFDADA89F4C5F84FB59A255778006, mem on start (mb), free: 70, total: 509, max: 672
2016-05-18 05:03:27,405 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A46BFDADA89F4C5F84FB59A255778006, mem on close (mb), free: 70, total: 509, max: 672
2016-05-18 05:03:27,419 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:27,419 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,426 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EE381AEF9F874AC59B8BE19E0C77B654, ordinal: 1
2016-05-18 05:03:27,427 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 05:03:27,427 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-18 05:03:27,427 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE381AEF9F874AC59B8BE19E0C77B654, mem on start (mb), free: 68, total: 509, max: 672
2016-05-18 05:03:27,432 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 05:03:27,432 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 05:03:27,433 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:635)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.accept(HadoopGroupGate.java:147)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:146)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2016-05-18 05:03:27,436 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE381AEF9F874AC59B8BE19E0C77B654, mem on close (mb), free: 68, total: 509, max: 672
2016-05-18 05:03:27,438 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local1464117486_0010
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:635)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.accept(HadoopGroupGate.java:147)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:146)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2016-05-18 05:03:27,440 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] hadoop job job_local1464117486_0010 state at FAILED
2016-05-18 05:03:27,442 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] failure info: NA
2016-05-18 05:03:27,442 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events identify failed tasks
2016-05-18 05:03:27,442 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events count: 0
2016-05-18 05:03:27,449 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping all jobs
2016-05-18 05:03:27,449 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 05:03:27,450 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopped all jobs
2016-05-18 05:03:27,450 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testOOMEPostGroup/oomepost/_temporary
2016-05-18 05:03:27,451 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.326
exception = cascading.flow.FlowException: local step failed: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 05:03:27,453 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testOOMEPostGroup/oomepost
2016-05-18 05:03:27,463 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:27,464 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:27,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 05:03:27,518 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:03:27,520 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:27,538 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:27,538 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-05-18 05:03:27,539 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.2.x/build/test/output/hadoop/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-18 05:03:27,539 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:27,539 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:27,539 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:27,540 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...Modified/lasteachmodified
2016-05-18 05:03:27,575 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1682331698_0011
2016-05-18 05:03:27,576 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:27,580 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.10.txt
2016-05-18 05:03:27,623 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:27,624 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,630 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AFDECEBAD8144BA4AD60F21F76F61047, ordinal: 0
2016-05-18 05:03:27,631 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-05-18 05:03:27,631 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2016-05-18 05:03:27,631 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AFDECEBAD8144BA4AD60F21F76F61047, mem on start (mb), free: 72, total: 568, max: 672
2016-05-18 05:03:27,633 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AFDECEBAD8144BA4AD60F21F76F61047, mem on close (mb), free: 72, total: 568, max: 672
2016-05-18 05:03:27,643 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:27,643 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,650 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CD4F2A61B47641978DDB5E741A920D52, ordinal: 1
2016-05-18 05:03:27,650 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2016-05-18 05:03:27,650 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.2.x/build/test/output/hadoop/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-18 05:03:27,651 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CD4F2A61B47641978DDB5E741A920D52, mem on start (mb), free: 71, total: 568, max: 672
2016-05-18 05:03:27,657 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CD4F2A61B47641978DDB5E741A920D52, mem on close (mb), free: 71, total: 568, max: 672
2016-05-18 05:03:27,669 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testLastEachNotModified/lasteachmodified/_temporary
2016-05-18 05:03:27,670 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.131
2016-05-18 05:03:27,680 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testLastEachNotModified/lasteachmodified
2016-05-18 05:03:27,698 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:27,699 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:27,752 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.049
2016-05-18 05:03:27,754 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:27,754 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:27,765 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:27,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.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:27,767 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.2.x/build/test/output/hadoop/regressionpipesplatform/testUnknown/unknown"]
2016-05-18 05:03:27,767 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:27,768 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:27,768 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:27,769 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tform/testUnknown/unknown
2016-05-18 05:03:27,816 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1717210558_0012
2016-05-18 05:03:27,816 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:27,821 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:03:27,824 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:27,824 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,833 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5A4F5D3DD054BE9BF9B7170D069AB48, ordinal: 0
2016-05-18 05:03:27,834 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:27,834 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.2.x/build/test/output/hadoop/regressionpipesplatform/testUnknown/unknown"]
2016-05-18 05:03:27,834 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5A4F5D3DD054BE9BF9B7170D069AB48, mem on start (mb), free: 176, total: 568, max: 672
2016-05-18 05:03:27,835 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5A4F5D3DD054BE9BF9B7170D069AB48, mem on close (mb), free: 176, total: 568, max: 672
2016-05-18 05:03:27,849 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testUnknown/unknown/_temporary
2016-05-18 05:03:27,851 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.084
2016-05-18 05:03:27,862 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testUnknown/unknown
2016-05-18 05:03:27,877 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:27,877 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:27,913 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-18 05:03:27,915 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:27,915 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:27,932 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:27,932 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/critics.txt"]
2016-05-18 05:03:27,932 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.2.x/build/test/output/hadoop/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-18 05:03:27,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:27,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:27,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:27,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...orm/testVarWidth/varwidth
2016-05-18 05:03:27,957 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local570342414_0013
2016-05-18 05:03:27,957 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:27,961 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/critics.txt
2016-05-18 05:03:27,964 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:27,965 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:27,971 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C50D07CF82154018BE2D7E2C873DEB0A, ordinal: 0
2016-05-18 05:03:27,972 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/critics.txt"]
2016-05-18 05:03:27,972 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.2.x/build/test/output/hadoop/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-18 05:03:27,972 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C50D07CF82154018BE2D7E2C873DEB0A, mem on start (mb), free: 162, total: 568, max: 672
2016-05-18 05:03:27,974 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C50D07CF82154018BE2D7E2C873DEB0A, mem on close (mb), free: 162, total: 568, max: 672
2016-05-18 05:03:27,989 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testVarWidth/varwidth/_temporary
2016-05-18 05:03:27,990 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.057
2016-05-18 05:03:27,997 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testVarWidth/varwidth
2016-05-18 05:03:28,005 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:28,005 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:28,007 WARN planner.FlowPlanner (FlowPlanner.java:verifyPipeAssemblyEndPoints(464)) - duplicate head name found, not an error but heads should have unique names: 'test'
2016-05-18 05:03:28,008 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testDupeHeadNames/unknown
2016-05-18 05:03:28,017 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:28,018 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:28,020 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testDupeTailNames/unknown
2016-05-18 05:03:28,376 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:28,377 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:30,653 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:02.255
2016-05-18 05:03:30,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:03:30,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:30,863 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting
2016-05-18 05:03:30,863 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.200.txt"]
2016-05-18 05:03:30,863 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-18 05:03:30,863 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] parallel execution of steps is enabled: false
2016-05-18 05:03:30,864 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executing total steps: 1
2016-05-18 05:03:30,864 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] allocating management threads: 1
2016-05-18 05:03:30,864 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting step: (1/1) ...tDeepPipeline/deeppipline
2016-05-18 05:03:30,893 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] submitted hadoop job: job_local1414483645_0014
2016-05-18 05:03:30,893 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] tracking url: http://localhost:8080/
2016-05-18 05:03:30,899 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.200.txt
2016-05-18 05:03:30,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:30,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:31,088 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E73DD62AC1854B7EA64D28B345F1DF30, ordinal: 0
2016-05-18 05:03:31,121 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/apache.200.txt"]
2016-05-18 05:03:31,121 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-18 05:03:31,121 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E73DD62AC1854B7EA64D28B345F1DF30, mem on start (mb), free: 101, total: 683, max: 683
2016-05-18 05:03:31,352 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E73DD62AC1854B7EA64D28B345F1DF30, mem on close (mb), free: 93, total: 683, max: 683
2016-05-18 05:03:31,375 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:31,375 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:31,461 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AC0B429E0799486D86E46BDBFE1BF137, ordinal: 1
2016-05-18 05:03:31,480 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-18 05:03:31,480 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.2.x/build/test/output/hadoop/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-18 05:03:31,480 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AC0B429E0799486D86E46BDBFE1BF137, mem on start (mb), free: 87, total: 683, max: 683
2016-05-18 05:03:31,831 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AC0B429E0799486D86E46BDBFE1BF137, mem on close (mb), free: 80, total: 683, max: 683
2016-05-18 05:03:31,851 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testDeepPipeline/deeppipline/_temporary
2016-05-18 05:03:31,852 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] completed in: 00:00.988
2016-05-18 05:03:31,873 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testDeepPipeline/deeppipline
2016-05-18 05:03:31,887 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:31,888 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:31,914 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 05:03:31,916 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:31,916 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:31,926 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-18 05:03:31,926 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:03:31,927 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 05:03:31,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] parallel execution of steps is enabled: false
2016-05-18 05:03:31,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executing total steps: 1
2016-05-18 05:03:31,929 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] allocating management threads: 1
2016-05-18 05:03:31,931 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...litPipe/splitintermediate
2016-05-18 05:03:31,969 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local2137069435_0015
2016-05-18 05:03:31,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-18 05:03:31,976 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt
2016-05-18 05:03:31,980 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:31,980 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:31,985 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B1ADEEBE462F4158A229FFDAA5BD0122, ordinal: 0
2016-05-18 05:03:31,985 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:03:31,986 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 05:03:31,986 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1ADEEBE462F4158A229FFDAA5BD0122, mem on start (mb), free: 65, total: 683, max: 683
2016-05-18 05:03:31,988 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1ADEEBE462F4158A229FFDAA5BD0122, mem on close (mb), free: 65, total: 683, max: 683
2016-05-18 05:03:32,004 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/_temporary
2016-05-18 05:03:32,004 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] completed in: 00:00.077
2016-05-18 05:03:32,012 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:32,013 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:32,061 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-05-18 05:03:32,062 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:03:32,062 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:32,071 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting
2016-05-18 05:03:32,071 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 05:03:32,071 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-18 05:03:32,071 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] parallel execution of steps is enabled: false
2016-05-18 05:03:32,072 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executing total steps: 1
2016-05-18 05:03:32,072 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] allocating management threads: 1
2016-05-18 05:03:32,072 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting step: (1/1) ...pBySplitPipe/groupbysplit
2016-05-18 05:03:32,096 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] submitted hadoop job: job_local1793682980_0016
2016-05-18 05:03:32,096 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] tracking url: http://localhost:8080/
2016-05-18 05:03:32,100 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/part-00000
2016-05-18 05:03:32,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:32,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,120 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BC5FC1EBD4EA46C6AEA23F760CA3A9CF, ordinal: 0
2016-05-18 05:03:32,120 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 05:03:32,120 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-18 05:03:32,120 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC5FC1EBD4EA46C6AEA23F760CA3A9CF, mem on start (mb), free: 175, total: 675, max: 675
2016-05-18 05:03:32,122 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC5FC1EBD4EA46C6AEA23F760CA3A9CF, mem on close (mb), free: 175, total: 675, max: 675
2016-05-18 05:03:32,131 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:32,131 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,136 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C9A03BACE876437E93A0CC6DADF5A2E7, ordinal: 1
2016-05-18 05:03:32,136 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-18 05:03:32,136 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-18 05:03:32,137 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C9A03BACE876437E93A0CC6DADF5A2E7, mem on start (mb), free: 174, total: 675, max: 675
2016-05-18 05:03:32,142 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C9A03BACE876437E93A0CC6DADF5A2E7, mem on close (mb), free: 174, total: 675, max: 675
2016-05-18 05:03:32,149 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testGroupBySplitPipe/groupbysplit/_temporary
2016-05-18 05:03:32,150 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] completed in: 00:00.078
2016-05-18 05:03:32,167 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testGroupBySplitPipe/splitintermediate
2016-05-18 05:03:32,167 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testGroupBySplitPipe/groupbysplit
2016-05-18 05:03:32,177 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:32,178 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:32,230 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.048
2016-05-18 05:03:32,232 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 05:03:32,232 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:32,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting
2016-05-18 05:03:32,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:32,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-18 05:03:32,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] parallel execution of steps is enabled: false
2016-05-18 05:03:32,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executing total steps: 2
2016-05-18 05:03:32,257 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] allocating management threads: 1
2016-05-18 05:03:32,258 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2016-05-18 05:03:32,291 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local1060122710_0017
2016-05-18 05:03:32,294 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-18 05:03:32,296 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:03:32,627 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:32,628 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,632 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: ABFD77421FE2471EB436D3EC8A0B705A, ordinal: 0
2016-05-18 05:03:32,633 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:32,633 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 05:03:32,633 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ABFD77421FE2471EB436D3EC8A0B705A, mem on start (mb), free: 361, total: 469, max: 672
2016-05-18 05:03:32,634 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ABFD77421FE2471EB436D3EC8A0B705A, mem on close (mb), free: 361, total: 469, max: 672
2016-05-18 05:03:32,642 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:32,642 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,646 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B4464BB80E6E430EBF04B5918D534764, ordinal: 1
2016-05-18 05:03:32,646 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 05:03:32,646 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][8681341756/__&%&%bar:bar@foo:_blah_/]
2016-05-18 05:03:32,647 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B4464BB80E6E430EBF04B5918D534764, mem on start (mb), free: 358, total: 469, max: 672
2016-05-18 05:03:32,656 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B4464BB80E6E430EBF04B5918D534764, mem on close (mb), free: 357, total: 469, max: 672
2016-05-18 05:03:32,666 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...sInTempFiles/illegalchars
2016-05-18 05:03:32,687 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local689197305_0018
2016-05-18 05:03:32,687 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-18 05:03:32,691 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8681341756____bar_bar_foo__blah__235865BBD5A14469BBC059E49D7CE0A7/part-00000
2016-05-18 05:03:32,711 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:32,711 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,716 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F52C93A253484BC3B25952F55F42993C, ordinal: 0
2016-05-18 05:03:32,716 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][8681341756/__&%&%bar:bar@foo:_blah_/]
2016-05-18 05:03:32,717 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 05:03:32,717 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F52C93A253484BC3B25952F55F42993C, mem on start (mb), free: 251, total: 469, max: 672
2016-05-18 05:03:32,719 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F52C93A253484BC3B25952F55F42993C, mem on close (mb), free: 251, total: 469, max: 672
2016-05-18 05:03:32,730 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:03:32,730 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,736 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EE0876D3FC4645FD8C1772A6861E071E, ordinal: 1
2016-05-18 05:03:32,737 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 05:03:32,737 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.2.x/build/test/output/hadoop/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-18 05:03:32,737 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE0876D3FC4645FD8C1772A6861E071E, mem on start (mb), free: 249, total: 469, max: 672
2016-05-18 05:03:32,742 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE0876D3FC4645FD8C1772A6861E071E, mem on close (mb), free: 248, total: 469, max: 672
2016-05-18 05:03:32,753 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars/_temporary
2016-05-18 05:03:32,753 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] completed in: 00:00.497
2016-05-18 05:03:32,760 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars
2016-05-18 05:03:32,768 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:03:32,769 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:03:32,787 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-05-18 05:03:32,787 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:03:32,788 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:03:32,794 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:03:32,795 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:32,795 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.2.x/build/test/output/hadoop/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-18 05:03:32,795 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 05:03:32,795 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 05:03:32,795 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 05:03:32,796 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2016-05-18 05:03:32,820 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1926072303_0019
2016-05-18 05:03:32,821 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:03:32,824 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:03:32,828 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:03:32,829 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:03:32,835 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FF4ADA41B0434444B1BE21D4537FB516, ordinal: 0
2016-05-18 05:03:32,836 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:03:32,836 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.2.x/build/test/output/hadoop/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-18 05:03:32,836 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FF4ADA41B0434444B1BE21D4537FB516, mem on start (mb), free: 233, total: 469, max: 672
2016-05-18 05:03:32,838 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FF4ADA41B0434444B1BE21D4537FB516, mem on close (mb), free: 233, total: 469, max: 672
2016-05-18 05:03:32,852 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic/_temporary
2016-05-18 05:03:32,853 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.058
2016-05-18 05:03:32,860 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic