2014-08-22 16:39:55,071 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2014-08-22 16:39:55,121 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2014-08-22 16:39:55,122 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.BufferPipesPlatformTest
2014-08-22 16:39:55,152 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2014-08-22 16:39:55,557 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:39:55,560 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 16:39:55,573 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: E232C86D35F540438CF9B7FB396C155D
2014-08-22 16:39:55,801 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.5.6
2014-08-22 16:39:55,805 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 16:39:55,806 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt"]
2014-08-22 16:39:55,806 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/identity"]
2014-08-22 16:39:55,807 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 16:39:55,807 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 16:39:55,808 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 16:39:55,810 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ferpipesplatform/identity
2014-08-22 16:39:55,857 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2014-08-22 16:39:55,926 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2014-08-22 16:39:55,930 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:56,180 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0001
2014-08-22 16:39:56,183 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 16:39:56,251 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(63)) - setsid exited with exit code 0
2014-08-22 16:39:56,259 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@b22c9df
2014-08-22 16:39:56,268 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt
2014-08-22 16:39:56,281 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:39:56,291 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:39:56,435 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:39:56,436 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:39:56,462 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:39:56,462 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:39:56,533 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt"]
2014-08-22 16:39:56,533 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:56,548 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:39:56,561 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:39:56,564 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0001_m_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:56,568 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt:0+52
2014-08-22 16:39:56,569 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0001_m_000000_0' done.
2014-08-22 16:39:56,580 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@438d460
2014-08-22 16:39:56,580 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:56,586 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 16:39:56,593 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 1 segments left of total size: 223 bytes
2014-08-22 16:39:56,593 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:56,595 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 16:39:56,595 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 16:39:56,614 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:56,614 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/identity"]
2014-08-22 16:39:56,637 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0001_r_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:56,638 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:56,639 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0001_r_000000_0 is allowed to commit now
2014-08-22 16:39:56,643 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0001_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/identity
2014-08-22 16:39:56,644 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2014-08-22 16:39:56,645 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0001_r_000000_0' done.
2014-08-22 16:39:56,656 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/identity/_temporary
2014-08-22 16:39:56,681 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:56,705 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:56,708 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/identity
2014-08-22 16:39:56,735 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:39:56,737 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 16:39:56,773 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 16:39:56,774 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt"]
2014-08-22 16:39:56,774 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple"]
2014-08-22 16:39:56,774 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 16:39:56,775 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 16:39:56,775 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 16:39:56,776 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ufferpipesplatform/simple
2014-08-22 16:39:56,792 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:56,888 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0002
2014-08-22 16:39:56,889 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 16:39:56,893 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5de82b72
2014-08-22 16:39:56,896 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt
2014-08-22 16:39:56,898 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:39:56,899 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:39:57,038 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:39:57,039 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:39:57,040 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:39:57,041 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:39:57,057 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt"]
2014-08-22 16:39:57,057 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:57,062 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:39:57,067 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:39:57,069 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0002_m_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:57,071 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt:0+52
2014-08-22 16:39:57,072 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0002_m_000000_0' done.
2014-08-22 16:39:57,078 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@34b6a6d6
2014-08-22 16:39:57,079 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:57,080 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 16:39:57,082 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 1 segments left of total size: 223 bytes
2014-08-22 16:39:57,082 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:57,084 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 16:39:57,084 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 16:39:57,096 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:57,097 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple"]
2014-08-22 16:39:57,107 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0002_r_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:57,109 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:57,110 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0002_r_000000_0 is allowed to commit now
2014-08-22 16:39:57,114 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0002_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple
2014-08-22 16:39:57,115 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2014-08-22 16:39:57,116 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0002_r_000000_0' done.
2014-08-22 16:39:57,122 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple/_temporary
2014-08-22 16:39:57,143 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,167 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,170 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/simple
2014-08-22 16:39:57,192 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:39:57,193 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 16:39:57,238 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] starting
2014-08-22 16:39:57,239 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/upper.txt"]
2014-08-22 16:39:57,239 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower.txt"]
2014-08-22 16:39:57,239 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/cogroup"]
2014-08-22 16:39:57,240 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] parallel execution is enabled: false
2014-08-22 16:39:57,240 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] starting jobs: 1
2014-08-22 16:39:57,240 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] allocating threads: 1
2014-08-22 16:39:57,241 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] starting step: (1/1) ...fferpipesplatform/cogroup
2014-08-22 16:39:57,258 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,260 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,308 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] submitted hadoop job: job_local_0003
2014-08-22 16:39:57,308 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] tracking url: http://localhost:8080/
2014-08-22 16:39:57,313 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@7e566633
2014-08-22 16:39:57,315 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower.txt
2014-08-22 16:39:57,317 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:39:57,318 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:39:57,452 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:39:57,452 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:39:57,456 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:39:57,456 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:39:57,474 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower.txt"]
2014-08-22 16:39:57,474 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2014-08-22 16:39:57,477 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:39:57,481 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:39:57,484 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0003_m_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:57,485 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower.txt:0+19
2014-08-22 16:39:57,486 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0003_m_000000_0' done.
2014-08-22 16:39:57,489 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4b94ba17
2014-08-22 16:39:57,491 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/upper.txt
2014-08-22 16:39:57,492 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:39:57,493 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:39:57,642 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:39:57,642 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:39:57,644 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:39:57,644 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:39:57,658 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/upper.txt"]
2014-08-22 16:39:57,658 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2014-08-22 16:39:57,661 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:39:57,666 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:39:57,668 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0003_m_000001_0 is done. And is in the process of commiting
2014-08-22 16:39:57,670 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/upper.txt:0+19
2014-08-22 16:39:57,671 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0003_m_000001_0' done.
2014-08-22 16:39:57,681 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6af2f0d0
2014-08-22 16:39:57,681 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:57,683 INFO mapred.Merger (Merger.java:merge(390)) - Merging 2 sorted segments
2014-08-22 16:39:57,684 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 2 segments left of total size: 194 bytes
2014-08-22 16:39:57,685 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:57,687 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 16:39:57,687 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 16:39:57,702 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2014-08-22 16:39:57,702 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/cogroup"]
2014-08-22 16:39:57,717 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2014-08-22 16:39:57,718 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2014-08-22 16:39:57,729 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0003_r_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:57,730 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:57,731 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0003_r_000000_0 is allowed to commit now
2014-08-22 16:39:57,736 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0003_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/cogroup
2014-08-22 16:39:57,736 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2014-08-22 16:39:57,737 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0003_r_000000_0' done.
2014-08-22 16:39:57,753 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/cogroup/_temporary
2014-08-22 16:39:57,765 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,779 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,781 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/cogroup
2014-08-22 16:39:57,794 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:39:57,795 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 16:39:57,823 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 16:39:57,824 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt"]
2014-08-22 16:39:57,824 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple2"]
2014-08-22 16:39:57,824 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 16:39:57,824 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 16:39:57,825 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 16:39:57,825 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...fferpipesplatform/simple2
2014-08-22 16:39:57,840 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:57,882 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0004
2014-08-22 16:39:57,883 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 16:39:57,887 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@1925d92c
2014-08-22 16:39:57,889 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt
2014-08-22 16:39:57,891 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:39:57,892 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:39:58,023 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:39:58,024 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:39:58,026 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:39:58,026 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:39:58,037 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt"]
2014-08-22 16:39:58,038 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:58,042 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:39:58,047 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:39:58,049 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0004_m_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:58,051 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lhs.txt:0+52
2014-08-22 16:39:58,052 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0004_m_000000_0' done.
2014-08-22 16:39:58,058 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@39849daf
2014-08-22 16:39:58,059 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:58,061 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 16:39:58,062 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 1 segments left of total size: 223 bytes
2014-08-22 16:39:58,062 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:58,064 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 16:39:58,064 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 16:39:58,077 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:58,077 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple2"]
2014-08-22 16:39:58,087 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0004_r_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:58,088 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:58,089 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0004_r_000000_0 is allowed to commit now
2014-08-22 16:39:58,093 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0004_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple2
2014-08-22 16:39:58,094 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2014-08-22 16:39:58,095 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0004_r_000000_0' done.
2014-08-22 16:39:58,106 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple2/_temporary
2014-08-22 16:39:58,119 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:58,133 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:58,135 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/simple2
2014-08-22 16:39:58,148 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:39:58,162 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 16:39:58,189 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 16:39:58,189 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower+upper.txt"]
2014-08-22 16:39:58,190 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple3"]
2014-08-22 16:39:58,190 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 16:39:58,190 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 16:39:58,191 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 16:39:58,191 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...fferpipesplatform/simple3
2014-08-22 16:39:58,207 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:58,245 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0005
2014-08-22 16:39:58,245 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 16:39:58,249 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@470898b
2014-08-22 16:39:58,251 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower+upper.txt
2014-08-22 16:39:58,253 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:39:58,254 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:39:58,599 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:39:58,601 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:39:58,603 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:39:58,604 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:39:58,614 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower+upper.txt"]
2014-08-22 16:39:58,615 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:58,618 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:39:58,621 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:39:58,623 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0005_m_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:58,626 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/lower+upper.txt:0+30
2014-08-22 16:39:58,627 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0005_m_000000_0' done.
2014-08-22 16:39:58,632 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@2f2e43f1
2014-08-22 16:39:58,633 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:58,634 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 16:39:58,635 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 1 segments left of total size: 117 bytes
2014-08-22 16:39:58,636 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:58,637 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 16:39:58,638 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 16:39:58,649 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 16:39:58,650 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple3"]
2014-08-22 16:39:58,658 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0005_r_000000_0 is done. And is in the process of commiting
2014-08-22 16:39:58,659 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:39:58,660 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0005_r_000000_0 is allowed to commit now
2014-08-22 16:39:58,664 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0005_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple3
2014-08-22 16:39:58,665 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2014-08-22 16:39:58,666 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0005_r_000000_0' done.
2014-08-22 16:39:58,681 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/simple3/_temporary
2014-08-22 16:39:58,693 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:58,707 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:39:58,709 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/simple3
2014-08-22 16:39:58,724 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:39:58,725 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar