2014-08-22 14:56:56,267 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2014-08-22 14:56:56,321 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2014-08-22 14:56:56,321 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.BufferPipesPlatformTest
2014-08-22 14:56:56,355 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2014-08-22 14:56:56,780 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 14:56:56,782 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 14:56:56,795 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: B7850B0D917D42BA8110F353C9731256
2014-08-22 14:56:57,024 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.5.6
2014-08-22 14:56:57,029 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 14:56:57,030 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2014-08-22 14:56:57,030 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/identity"]
2014-08-22 14:56:57,031 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 14:56:57,031 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 14:56:57,032 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 14:56:57,033 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ferpipesplatform/identity
2014-08-22 14:56:57,076 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 14:56:57,127 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:56:57,344 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0001
2014-08-22 14:56:57,345 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 14:56:57,411 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(63)) - setsid exited with exit code 0
2014-08-22 14:56:57,418 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@424c414
2014-08-22 14:56:57,426 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt
2014-08-22 14:56:57,433 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 14:56:57,442 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 14:56:57,587 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 14:56:57,587 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 14:56:57,612 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 14:56:57,612 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 14:56:57,685 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2014-08-22 14:56:57,685 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:56:57,699 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 14:56:57,712 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 14:56:57,715 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0001_m_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:00,395 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt:0+52
2014-08-22 14:57:00,396 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0001_m_000000_0' done.
2014-08-22 14:57:00,413 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@2c61ec49
2014-08-22 14:57:00,413 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:00,419 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 14:57:00,424 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 14:57:00,424 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:00,426 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 14:57:00,426 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 14:57:00,445 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:00,445 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/identity"]
2014-08-22 14:57:00,468 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0001_r_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:00,469 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:00,470 INFO mapred.Task (Task.java:commit(1000)) - Task attempt_local_0001_r_000000_0 is allowed to commit now
2014-08-22 14:57:00,474 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-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/identity
2014-08-22 14:57:03,412 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - reduce > reduce
2014-08-22 14:57:03,414 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0001_r_000000_0' done.
2014-08-22 14:57:03,426 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/identity/_temporary
2014-08-22 14:57:03,452 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:03,476 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:03,478 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/identity
2014-08-22 14:57:03,505 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 14:57:03,505 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 14:57:03,540 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 14:57:03,541 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2014-08-22 14:57:03,541 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple"]
2014-08-22 14:57:03,542 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 14:57:03,542 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 14:57:03,542 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 14:57:03,544 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ufferpipesplatform/simple
2014-08-22 14:57:03,563 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:03,648 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0002
2014-08-22 14:57:03,649 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 14:57:03,654 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4e300429
2014-08-22 14:57:03,656 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt
2014-08-22 14:57:03,658 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 14:57:03,659 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 14:57:03,794 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 14:57:03,795 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 14:57:03,797 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 14:57:03,798 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 14:57:03,814 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2014-08-22 14:57:03,814 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:03,819 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 14:57:03,823 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 14:57:03,826 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0002_m_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:06,654 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt:0+52
2014-08-22 14:57:06,657 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0002_m_000000_0' done.
2014-08-22 14:57:06,662 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@752d7d02
2014-08-22 14:57:06,663 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:06,664 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 14:57:06,665 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 14:57:06,665 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:06,667 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 14:57:06,667 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 14:57:06,680 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:06,680 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple"]
2014-08-22 14:57:06,691 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0002_r_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:06,691 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:06,692 INFO mapred.Task (Task.java:commit(1000)) - Task attempt_local_0002_r_000000_0 is allowed to commit now
2014-08-22 14:57:06,697 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-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple
2014-08-22 14:57:09,662 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - reduce > reduce
2014-08-22 14:57:09,663 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0002_r_000000_0' done.
2014-08-22 14:57:09,674 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple/_temporary
2014-08-22 14:57:09,695 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:09,718 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:09,720 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/simple
2014-08-22 14:57:09,743 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 14:57:09,744 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 14:57:09,801 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] starting
2014-08-22 14:57:09,802 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2014-08-22 14:57:09,802 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2014-08-22 14:57:09,802 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/cogroup"]
2014-08-22 14:57:09,803 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] parallel execution is enabled: false
2014-08-22 14:57:09,803 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] starting jobs: 1
2014-08-22 14:57:09,803 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [lower*upper] allocating threads: 1
2014-08-22 14:57:09,804 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] starting step: (1/1) ...fferpipesplatform/cogroup
2014-08-22 14:57:09,823 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:09,824 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:09,891 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] submitted hadoop job: job_local_0003
2014-08-22 14:57:09,893 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] tracking url: http://localhost:8080/
2014-08-22 14:57:09,900 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4fc64ed8
2014-08-22 14:57:09,902 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower.txt
2014-08-22 14:57:09,904 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 14:57:09,904 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 14:57:10,045 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 14:57:10,045 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 14:57:10,048 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 14:57:10,048 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 14:57:10,063 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2014-08-22 14:57:10,064 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2014-08-22 14:57:10,066 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 14:57:10,070 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 14:57:10,073 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0003_m_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:12,901 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower.txt:0+19
2014-08-22 14:57:12,902 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0003_m_000000_0' done.
2014-08-22 14:57:12,904 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@13ce64f6
2014-08-22 14:57:12,905 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/upper.txt
2014-08-22 14:57:12,907 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 14:57:12,907 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 14:57:13,038 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 14:57:13,039 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 14:57:13,040 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 14:57:13,040 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 14:57:13,053 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2014-08-22 14:57:13,053 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2014-08-22 14:57:13,056 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 14:57:13,060 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 14:57:13,062 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0003_m_000001_0 is done. And is in the process of commiting
2014-08-22 14:57:15,904 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/upper.txt:0+19
2014-08-22 14:57:15,905 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0003_m_000001_0' done.
2014-08-22 14:57:15,916 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3fb35ece
2014-08-22 14:57:15,917 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:15,919 INFO mapred.Merger (Merger.java:merge(390)) - Merging 2 sorted segments
2014-08-22 14:57:15,920 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 14:57:15,921 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:15,922 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 14:57:15,923 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 14:57:15,934 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2014-08-22 14:57:15,935 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/cogroup"]
2014-08-22 14:57:15,952 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2014-08-22 14:57:15,952 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2014-08-22 14:57:15,961 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0003_r_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:15,962 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:15,963 INFO mapred.Task (Task.java:commit(1000)) - Task attempt_local_0003_r_000000_0 is allowed to commit now
2014-08-22 14:57:15,967 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-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/cogroup
2014-08-22 14:57:18,917 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - reduce > reduce
2014-08-22 14:57:18,918 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0003_r_000000_0' done.
2014-08-22 14:57:18,926 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/cogroup/_temporary
2014-08-22 14:57:18,939 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:18,953 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:18,955 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/cogroup
2014-08-22 14:57:18,968 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 14:57:18,969 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 14:57:18,995 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 14:57:18,998 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2014-08-22 14:57:18,998 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple2"]
2014-08-22 14:57:18,999 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 14:57:19,000 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 14:57:19,000 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 14:57:19,001 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...fferpipesplatform/simple2
2014-08-22 14:57:19,018 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:19,058 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0004
2014-08-22 14:57:19,059 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 14:57:19,062 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@7e92997e
2014-08-22 14:57:19,064 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt
2014-08-22 14:57:19,066 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 14:57:19,066 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 14:57:19,210 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 14:57:19,212 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 14:57:19,218 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 14:57:19,218 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 14:57:19,229 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2014-08-22 14:57:19,229 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:19,233 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 14:57:19,237 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 14:57:19,240 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0004_m_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:22,063 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lhs.txt:0+52
2014-08-22 14:57:22,064 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0004_m_000000_0' done.
2014-08-22 14:57:22,070 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@c9c6201
2014-08-22 14:57:22,070 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:22,071 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 14:57:22,072 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 14:57:22,072 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:22,073 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 14:57:22,073 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 14:57:22,085 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:22,085 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple2"]
2014-08-22 14:57:22,094 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0004_r_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:22,095 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:22,096 INFO mapred.Task (Task.java:commit(1000)) - Task attempt_local_0004_r_000000_0 is allowed to commit now
2014-08-22 14:57:22,100 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-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple2
2014-08-22 14:57:25,069 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - reduce > reduce
2014-08-22 14:57:25,070 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0004_r_000000_0' done.
2014-08-22 14:57:25,080 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple2/_temporary
2014-08-22 14:57:25,093 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:25,106 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:25,108 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/simple2
2014-08-22 14:57:25,121 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 14:57:25,122 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 14:57:25,146 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 14:57:25,146 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower+upper.txt"]
2014-08-22 14:57:25,147 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple3"]
2014-08-22 14:57:25,148 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 14:57:25,148 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 14:57:25,148 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 14:57:25,149 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...fferpipesplatform/simple3
2014-08-22 14:57:25,165 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:25,201 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local_0005
2014-08-22 14:57:25,201 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 14:57:25,205 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@22fe135d
2014-08-22 14:57:25,207 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower+upper.txt
2014-08-22 14:57:25,208 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 14:57:25,208 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 14:57:25,539 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 14:57:25,539 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 14:57:25,541 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 14:57:25,541 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 14:57:25,550 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower+upper.txt"]
2014-08-22 14:57:25,550 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:25,553 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 14:57:25,556 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 14:57:25,558 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0005_m_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:28,205 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/classes/test/data/lower+upper.txt:0+30
2014-08-22 14:57:28,206 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0005_m_000000_0' done.
2014-08-22 14:57:28,211 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@2180e7a4
2014-08-22 14:57:28,211 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:28,212 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 14:57:28,213 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 14:57:28,213 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:28,214 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 14:57:28,214 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 14:57:28,223 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2014-08-22 14:57:28,223 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple3"]
2014-08-22 14:57:28,231 INFO mapred.Task (Task.java:done(847)) - Task:attempt_local_0005_r_000000_0 is done. And is in the process of commiting
2014-08-22 14:57:28,231 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) -
2014-08-22 14:57:28,232 INFO mapred.Task (Task.java:commit(1000)) - Task attempt_local_0005_r_000000_0 is allowed to commit now
2014-08-22 14:57:28,236 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-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple3
2014-08-22 14:57:31,211 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(321)) - reduce > reduce
2014-08-22 14:57:31,212 INFO mapred.Task (Task.java:sendDone(959)) - Task 'attempt_local_0005_r_000000_0' done.
2014-08-22 14:57:31,223 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/simple3/_temporary
2014-08-22 14:57:31,234 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:31,246 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 14:57:31,248 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/simple3
2014-08-22 14:57:31,261 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 14:57:31,262 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