2014-08-22 16:59:54,807 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2014-08-22 16:59:54,856 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2014-08-22 16:59:54,857 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.function.FunctionPlatformTest
2014-08-22 16:59:54,888 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2014-08-22 16:59:55,227 INFO assembly.AggregateBy (AggregateBy.java:prepare(248)) - using threshold value: 2
2014-08-22 16:59:55,233 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 1, with threshold: 2
2014-08-22 16:59:55,234 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 94, total: 102, max: 672
2014-08-22 16:59:55,235 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(313)) - total mem is 15% of max mem, to better utilize unused memory consider increasing current LRU threshold with system property "cascading.aggregateby.threshold"
2014-08-22 16:59:55,236 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 3, with threshold: 2
2014-08-22 16:59:55,237 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 94, total: 102, max: 672
2014-08-22 16:59:55,238 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(313)) - total mem is 15% of max mem, to better utilize unused memory consider increasing current LRU threshold with system property "cascading.aggregateby.threshold"
2014-08-22 16:59:55,330 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:59:55,333 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:59:55,346 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: CD8F71A63B574308A1457464565BB674
2014-08-22 16:59:55,552 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.5.6
2014-08-22 16:59:55,555 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [formatter] starting
2014-08-22 16:59:55,556 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [formatter] 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:59:55,557 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [formatter] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter"]
2014-08-22 16:59:55,557 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [formatter] parallel execution is enabled: false
2014-08-22 16:59:55,558 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [formatter] starting jobs: 1
2014-08-22 16:59:55,558 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [formatter] allocating threads: 1
2014-08-22 16:59:55,559 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [formatter] starting step: (1/1) ...unctionplatform/formatter
2014-08-22 16:59:55,607 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:59:55,675 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2014-08-22 16:59:55,679 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:55,928 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [formatter] submitted hadoop job: job_local_0001
2014-08-22 16:59:55,929 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [formatter] tracking url: http://localhost:8080/
2014-08-22 16:59:56,001 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(63)) - setsid exited with exit code 0
2014-08-22 16:59:56,016 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@56b61c3
2014-08-22 16:59:56,024 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:59:56,032 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 0
2014-08-22 16:59:56,043 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:59:56,043 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:59:56,091 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:59:56,091 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter"]
2014-08-22 16:59:56,105 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:59:56,108 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:59:56,109 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0001_m_000000_0 is allowed to commit now
2014-08-22 16:59:56,114 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0001_m_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter
2014-08-22 16:59:56,115 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:59:56,116 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0001_m_000000_0' done.
2014-08-22 16:59:56,128 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/functionplatform/formatter/_temporary
2014-08-22 16:59:56,154 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:56,181 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:56,184 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/functionplatform/formatter
2014-08-22 16:59:56,186 INFO assembly.AggregateBy (AggregateBy.java:prepare(248)) - using threshold value: 2
2014-08-22 16:59:56,188 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 1, with threshold: 2
2014-08-22 16:59:56,188 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 93, total: 102, max: 672
2014-08-22 16:59:56,189 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(313)) - total mem is 15% of max mem, to better utilize unused memory consider increasing current LRU threshold with system property "cascading.aggregateby.threshold"
2014-08-22 16:59:56,190 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 3, with threshold: 2
2014-08-22 16:59:56,191 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 92, total: 102, max: 672
2014-08-22 16:59:56,191 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(313)) - total mem is 15% of max mem, to better utilize unused memory consider increasing current LRU threshold with system property "cascading.aggregateby.threshold"
2014-08-22 16:59:56,222 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:59:56,223 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:59:56,265 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [apache] starting
2014-08-22 16:59:56,265 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [apache] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/apache.200.txt"]
2014-08-22 16:59:56,266 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [apache] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/insert"]
2014-08-22 16:59:56,266 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [apache] parallel execution is enabled: false
2014-08-22 16:59:56,266 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [apache] starting jobs: 1
2014-08-22 16:59:56,267 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [apache] allocating threads: 1
2014-08-22 16:59:56,267 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [apache] starting step: (1/1) ...p/functionplatform/insert
2014-08-22 16:59:56,284 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:56,381 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [apache] submitted hadoop job: job_local_0002
2014-08-22 16:59:56,381 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [apache] tracking url: http://localhost:8080/
2014-08-22 16:59:56,386 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@2b8ca663
2014-08-22 16:59:56,388 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/apache.200.txt
2014-08-22 16:59:56,390 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2014-08-22 16:59:56,400 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2014-08-22 16:59:56,540 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2014-08-22 16:59:56,541 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2014-08-22 16:59:56,561 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:59:56,561 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:59:56,582 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/apache.200.txt"]
2014-08-22 16:59:56,582 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(apache)[by:[{1}:'A']]
2014-08-22 16:59:56,624 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2014-08-22 16:59:56,646 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2014-08-22 16:59:56,649 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:59:56,651 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/classes/test/data/apache.200.txt:0+32599
2014-08-22 16:59:56,651 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0002_m_000000_0' done.
2014-08-22 16:59:56,661 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@47875da7
2014-08-22 16:59:56,662 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:59:56,668 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2014-08-22 16:59:56,674 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 1 segments left of total size: 3402 bytes
2014-08-22 16:59:56,674 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:59:56,676 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 16:59:56,677 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 16:59:56,691 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(apache)[by:[{1}:'A']]
2014-08-22 16:59:56,692 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/functionplatform/insert"]
2014-08-22 16:59:56,734 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:59:56,735 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:59:56,736 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0002_r_000000_0 is allowed to commit now
2014-08-22 16:59:56,740 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/functionplatform/insert
2014-08-22 16:59:56,741 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2014-08-22 16:59:56,742 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0002_r_000000_0' done.
2014-08-22 16:59:56,757 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/functionplatform/insert/_temporary
2014-08-22 16:59:56,778 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:56,807 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:56,815 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/functionplatform/insert
2014-08-22 16:59:56,843 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 16:59:56,844 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:59:56,872 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [setvalue] starting
2014-08-22 16:59:56,873 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [setvalue] 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:59:56,873 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [setvalue] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue"]
2014-08-22 16:59:56,874 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [setvalue] parallel execution is enabled: false
2014-08-22 16:59:56,874 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [setvalue] starting jobs: 1
2014-08-22 16:59:56,874 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [setvalue] allocating threads: 1
2014-08-22 16:59:56,875 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [setvalue] starting step: (1/1) ...functionplatform/setvalue
2014-08-22 16:59:56,890 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:56,944 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [setvalue] submitted hadoop job: job_local_0003
2014-08-22 16:59:56,944 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [setvalue] tracking url: http://localhost:8080/
2014-08-22 16:59:56,948 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@78a974c7
2014-08-22 16:59:56,951 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:59:56,953 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 0
2014-08-22 16:59:56,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 16:59:56,960 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 16:59:56,971 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:59:56,972 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue"]
2014-08-22 16:59:56,975 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:59:56,976 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2014-08-22 16:59:56,978 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0003_m_000000_0 is allowed to commit now
2014-08-22 16:59:56,982 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local_0003_m_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue
2014-08-22 16:59:56,983 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:59:56,984 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0003_m_000000_0' done.
2014-08-22 16:59:56,996 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/functionplatform/setvalue/_temporary
2014-08-22 16:59:57,010 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:57,025 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 16:59:57,027 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/functionplatform/setvalue