2013-11-20 13:35:30,467 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2013-11-20 13:35:30,493 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2013-11-20 13:35:30,494 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.function.FunctionPlatformTest
2013-11-20 13:35:30,521 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2013-11-20 13:35:30,835 INFO assembly.AggregateBy (AggregateBy.java:prepare(248)) - using threshold value: 2
2013-11-20 13:35:30,840 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 1, with threshold: 2
2013-11-20 13:35:30,840 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 97, total: 102, max: 672
2013-11-20 13:35:30,841 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"
2013-11-20 13:35:30,842 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 3, with threshold: 2
2013-11-20 13:35:30,843 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 97, total: 102, max: 672
2013-11-20 13:35:30,843 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"
2013-11-20 13:35:30,922 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 13:35:30,925 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 13:35:30,939 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: 6B110B66EA3C44E5A8967A239FD44948
2013-11-20 13:35:31,121 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.2.0
2013-11-20 13:35:31,125 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [formatter] starting
2013-11-20 13:35:31,125 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [formatter] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt"]
2013-11-20 13:35:31,126 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [formatter] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter"]
2013-11-20 13:35:31,126 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [formatter] parallel execution is enabled: false
2013-11-20 13:35:31,127 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [formatter] starting jobs: 1
2013-11-20 13:35:31,127 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [formatter] allocating threads: 1
2013-11-20 13:35:31,129 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [formatter] starting step: (1/1) ...unctionplatform/formatter
2013-11-20 13:35:31,175 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2013-11-20 13:35:31,240 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2013-11-20 13:35:31,248 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:31,476 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [formatter] submitted hadoop job: job_local_0001
2013-11-20 13:35:31,538 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(63)) - setsid exited with exit code 0
2013-11-20 13:35:31,547 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@749abce9
2013-11-20 13:35:31,556 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt
2013-11-20 13:35:31,564 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 0
2013-11-20 13:35:31,575 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 13:35:31,575 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 13:35:31,625 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt"]
2013-11-20 13:35:31,625 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter"]
2013-11-20 13:35:31,638 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0001_m_000000_0 is done. And is in the process of commiting
2013-11-20 13:35:31,641 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2013-11-20 13:35:31,642 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0001_m_000000_0 is allowed to commit now
2013-11-20 13:35:31,646 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/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter
2013-11-20 13:35:31,646 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt:0+19
2013-11-20 13:35:31,647 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0001_m_000000_0' done.
2013-11-20 13:35:31,662 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/formatter/_temporary
2013-11-20 13:35:31,686 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:31,709 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:31,711 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output//hadoop/functionplatform/formatter
2013-11-20 13:35:31,714 INFO assembly.AggregateBy (AggregateBy.java:prepare(248)) - using threshold value: 2
2013-11-20 13:35:31,715 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 1, with threshold: 2
2013-11-20 13:35:31,716 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 95, total: 102, max: 672
2013-11-20 13:35:31,716 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"
2013-11-20 13:35:31,717 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(307)) - flushed keys num times: 3, with threshold: 2
2013-11-20 13:35:31,718 INFO assembly.AggregateBy (AggregateBy.java:removeEldestEntry(308)) - mem on flush (mb), free: 95, total: 102, max: 672
2013-11-20 13:35:31,718 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"
2013-11-20 13:35:31,743 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 13:35:31,744 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 13:35:31,779 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [apache] starting
2013-11-20 13:35:31,779 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [apache] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/apache.200.txt"]
2013-11-20 13:35:31,780 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [apache] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/insert"]
2013-11-20 13:35:31,780 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [apache] parallel execution is enabled: false
2013-11-20 13:35:31,780 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [apache] starting jobs: 1
2013-11-20 13:35:31,781 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [apache] allocating threads: 1
2013-11-20 13:35:31,781 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [apache] starting step: (1/1) ...p/functionplatform/insert
2013-11-20 13:35:31,797 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:31,885 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [apache] submitted hadoop job: job_local_0002
2013-11-20 13:35:31,890 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6239da8a
2013-11-20 13:35:31,893 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/apache.200.txt
2013-11-20 13:35:31,895 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 1
2013-11-20 13:35:31,903 INFO mapred.MapTask (MapTask.java:<init>(944)) - io.sort.mb = 100
2013-11-20 13:35:32,026 INFO mapred.MapTask (MapTask.java:<init>(956)) - data buffer = 79691776/99614720
2013-11-20 13:35:32,026 INFO mapred.MapTask (MapTask.java:<init>(957)) - record buffer = 262144/327680
2013-11-20 13:35:32,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 13:35:32,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 13:35:32,062 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/apache.200.txt"]
2013-11-20 13:35:32,062 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(apache)[by:[{1}:'A']]
2013-11-20 13:35:32,099 INFO mapred.MapTask (MapTask.java:flush(1284)) - Starting flush of map output
2013-11-20 13:35:32,118 INFO mapred.MapTask (MapTask.java:sortAndSpill(1466)) - Finished spill 0
2013-11-20 13:35:32,121 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0002_m_000000_0 is done. And is in the process of commiting
2013-11-20 13:35:32,122 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/apache.200.txt:0+32599
2013-11-20 13:35:32,123 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0002_m_000000_0' done.
2013-11-20 13:35:32,133 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6460029d
2013-11-20 13:35:32,133 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2013-11-20 13:35:32,139 INFO mapred.Merger (Merger.java:merge(390)) - Merging 1 sorted segments
2013-11-20 13:35:32,145 INFO mapred.Merger (Merger.java:merge(473)) - Down to the last merge-pass, with 1 segments left of total size: 3402 bytes
2013-11-20 13:35:32,145 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2013-11-20 13:35:32,147 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 13:35:32,148 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 13:35:32,160 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(apache)[by:[{1}:'A']]
2013-11-20 13:35:32,161 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/insert"]
2013-11-20 13:35:32,199 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0002_r_000000_0 is done. And is in the process of commiting
2013-11-20 13:35:32,200 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2013-11-20 13:35:32,201 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0002_r_000000_0 is allowed to commit now
2013-11-20 13:35:32,205 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/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/insert
2013-11-20 13:35:32,206 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - reduce > reduce
2013-11-20 13:35:32,206 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0002_r_000000_0' done.
2013-11-20 13:35:32,220 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/insert/_temporary
2013-11-20 13:35:32,240 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:32,266 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:32,274 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output//hadoop/functionplatform/insert
2013-11-20 13:35:32,294 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 13:35:32,295 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 13:35:32,322 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [setvalue] starting
2013-11-20 13:35:32,323 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [setvalue] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt"]
2013-11-20 13:35:32,323 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [setvalue] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue"]
2013-11-20 13:35:32,324 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [setvalue] parallel execution is enabled: false
2013-11-20 13:35:32,331 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [setvalue] starting jobs: 1
2013-11-20 13:35:32,331 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [setvalue] allocating threads: 1
2013-11-20 13:35:32,332 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [setvalue] starting step: (1/1) ...functionplatform/setvalue
2013-11-20 13:35:32,347 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:32,397 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [setvalue] submitted hadoop job: job_local_0003
2013-11-20 13:35:32,402 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@79a93f38
2013-11-20 13:35:32,405 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt
2013-11-20 13:35:32,407 INFO mapred.MapTask (MapTask.java:runOldMapper(425)) - numReduceTasks: 0
2013-11-20 13:35:32,413 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 13:35:32,414 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 13:35:32,425 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt"]
2013-11-20 13:35:32,426 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue"]
2013-11-20 13:35:32,428 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local_0003_m_000000_0 is done. And is in the process of commiting
2013-11-20 13:35:32,429 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) -
2013-11-20 13:35:32,431 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local_0003_m_000000_0 is allowed to commit now
2013-11-20 13:35:32,434 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/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue
2013-11-20 13:35:32,435 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(323)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/classes/test/data/upper.txt:0+19
2013-11-20 13:35:32,436 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local_0003_m_000000_0' done.
2013-11-20 13:35:32,449 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output/hadoop/functionplatform/setvalue/_temporary
2013-11-20 13:35:32,462 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:32,475 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 13:35:32,478 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.1.x/build/test/output//hadoop/functionplatform/setvalue