Class cascading.DistanceUseCasePlatformTest

4

tests

0

failures

0

ignored

8.190s

duration

100%

successful

Tests

Test Duration Result
testEuclideanDistance 1.030s passed
testEuclideanDistanceComposite 4.779s passed
testEuclideanDistanceShort 0.972s passed
testPearsonDistanceComposite 1.409s passed

Standard output

2015-02-12 10:13:22,920 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-02-12 10:13:22,970 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-02-12 10:13:22,970 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.DistanceUseCasePlatformTest
2015-02-12 10:13:22,991 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-02-12 10:13:23,962 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-02-12 10:13:24,378 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 10:13:24,380 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 10:13:24,399 INFO  property.AppProps (AppProps.java:getAppID(169)) - using app.id: 6629C3B8A1654BAB81DF546EC4D443CD
2015-02-12 10:13:24,806 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:24,923 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:25,265 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 10:13:25,347 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 2.6.3
2015-02-12 10:13:25,349 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting
2015-02-12 10:13:25,349 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:25,350 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite"]
2015-02-12 10:13:25,350 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  parallel execution is enabled: false
2015-02-12 10:13:25,351 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  starting jobs: 3
2015-02-12 10:13:25,351 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  allocating threads: 1
2015-02-12 10:13:25,353 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2015-02-12 10:13:25,374 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2015-02-12 10:13:25,375 INFO  jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2015-02-12 10:13:25,397 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:25,751 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:25,833 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:26,034 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local776275881_0001
2015-02-12 10:13:26,200 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:26,202 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:26,210 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:26,224 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local776275881_0001
2015-02-12 10:13:26,224 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:26,237 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:26,240 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local776275881_0001_m_000000_0
2015-02-12 10:13:26,272 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:26,273 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:26,278 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt
2015-02-12 10:13:26,279 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7e406516
2015-02-12 10:13:26,287 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:26,351 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:26,351 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:26,351 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:26,351 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:26,351 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:26,369 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:26,370 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:26,370 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:26,416 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2015-02-12 10:13:26,429 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:26,430 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 10:13:26,444 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:26,444 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:26,445 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:26,445 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 10:13:26,445 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 10:13:26,458 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:26,463 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local776275881_0001_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:26,474 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt:0+828
2015-02-12 10:13:26,475 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local776275881_0001_m_000000_0' done.
2015-02-12 10:13:26,475 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local776275881_0001_m_000000_0
2015-02-12 10:13:26,476 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:26,479 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:26,479 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local776275881_0001_r_000000_0
2015-02-12 10:13:26,487 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:26,487 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:26,490 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@769706ad
2015-02-12 10:13:26,502 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:26,505 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local776275881_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:26,530 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#1 about to shuffle output of map attempt_local776275881_0001_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 10:13:26,534 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local776275881_0001_m_000000_0
2015-02-12 10:13:26,564 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 10:13:26,565 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:26,566 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:26,567 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:26,573 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:26,574 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:26,576 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:26,577 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 1822 bytes from disk
2015-02-12 10:13:26,577 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:26,578 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:26,578 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:26,579 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:26,581 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:26,581 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:26,598 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 10:13:26,599 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][9757561943/euclidean/]
2015-02-12 10:13:26,629 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:26,629 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:26,682 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local776275881_0001_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:26,684 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:26,684 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local776275881_0001_r_000000_0 is allowed to commit now
2015-02-12 10:13:26,686 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local776275881_0001_r_000000_0' to file:/tmp/hadoop-soberoi/9757561943_euclidean_BD576F1E7C8640FBB8126E9B0D28F2D9/_temporary/0/task_local776275881_0001_r_000000
2015-02-12 10:13:26,694 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:26,694 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local776275881_0001_r_000000_0' done.
2015-02-12 10:13:26,694 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local776275881_0001_r_000000_0
2015-02-12 10:13:26,695 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:26,734 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2015-02-12 10:13:26,735 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:26,737 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:26,817 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:26,838 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:26,853 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:26,854 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:26,869 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local1111432074_0002
2015-02-12 10:13:26,983 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:26,983 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:26,984 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:26,985 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local1111432074_0002
2015-02-12 10:13:26,987 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1111432074_0002_m_000000_0
2015-02-12 10:13:26,987 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:26,989 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:26,989 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:26,990 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/9757561943_euclidean_BD576F1E7C8640FBB8126E9B0D28F2D9/part-00000
2015-02-12 10:13:26,990 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@10112c38
2015-02-12 10:13:26,999 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:27,000 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:27,061 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:27,061 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:27,061 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:27,061 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:27,061 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:27,062 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:27,063 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:27,063 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:27,074 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][9757561943/euclidean/]
2015-02-12 10:13:27,074 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 10:13:27,099 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:27,099 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:27,100 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:27,100 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 10:13:27,100 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 10:13:27,135 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:27,137 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1111432074_0002_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:27,140 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/9757561943_euclidean_BD576F1E7C8640FBB8126E9B0D28F2D9/part-00000:0+13816
2015-02-12 10:13:27,140 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1111432074_0002_m_000000_0' done.
2015-02-12 10:13:27,140 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1111432074_0002_m_000000_0
2015-02-12 10:13:27,141 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:27,142 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:27,143 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1111432074_0002_r_000000_0
2015-02-12 10:13:27,145 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:27,145 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:27,145 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5a171d45
2015-02-12 10:13:27,146 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:27,146 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1111432074_0002_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:27,148 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#2 about to shuffle output of map attempt_local1111432074_0002_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 10:13:27,149 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local1111432074_0002_m_000000_0
2015-02-12 10:13:27,149 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 10:13:27,149 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:27,150 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:27,150 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:27,152 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:27,152 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:27,156 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:27,156 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 13458 bytes from disk
2015-02-12 10:13:27,156 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:27,156 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:27,157 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:27,157 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:27,157 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:27,158 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:27,168 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 10:13:27,168 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1995901330/euclidean/]
2015-02-12 10:13:27,198 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1111432074_0002_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:27,199 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:27,199 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1111432074_0002_r_000000_0 is allowed to commit now
2015-02-12 10:13:27,200 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1111432074_0002_r_000000_0' to file:/tmp/hadoop-soberoi/1995901330_euclidean_FABB1C375830463996CC706F5A1F3A24/_temporary/0/task_local1111432074_0002_r_000000
2015-02-12 10:13:27,201 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:27,202 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1111432074_0002_r_000000_0' done.
2015-02-12 10:13:27,202 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1111432074_0002_r_000000_0
2015-02-12 10:13:27,202 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:27,226 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...tform/euclidean/composite
2015-02-12 10:13:27,226 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:27,228 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:27,274 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:27,298 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:27,310 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:27,311 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:27,358 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local8313517_0003
2015-02-12 10:13:27,466 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:27,466 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:27,466 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:27,467 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local8313517_0003
2015-02-12 10:13:27,467 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:27,469 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:27,469 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local8313517_0003_m_000000_0
2015-02-12 10:13:27,471 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:27,472 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:27,474 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/1995901330_euclidean_FABB1C375830463996CC706F5A1F3A24/part-00000
2015-02-12 10:13:27,474 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1b460d97
2015-02-12 10:13:27,476 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:27,539 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:27,540 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:27,540 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:27,540 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:27,540 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:27,541 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:27,541 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:27,541 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:27,552 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1995901330/euclidean/]
2015-02-12 10:13:27,552 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2015-02-12 10:13:27,575 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:27,576 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:27,576 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:27,576 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 6291; bufvoid = 104857600
2015-02-12 10:13:27,577 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 10:13:27,583 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:27,585 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local8313517_0003_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:27,587 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/1995901330_euclidean_FABB1C375830463996CC706F5A1F3A24/part-00000:0+6943
2015-02-12 10:13:27,588 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local8313517_0003_m_000000_0' done.
2015-02-12 10:13:27,588 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local8313517_0003_m_000000_0
2015-02-12 10:13:27,588 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:27,588 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:27,589 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local8313517_0003_r_000000_0
2015-02-12 10:13:27,591 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:27,591 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:27,591 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@363ed80b
2015-02-12 10:13:27,591 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:27,592 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local8313517_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:27,594 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#3 about to shuffle output of map attempt_local8313517_0003_m_000000_0 decomp: 6467 len: 6471 to MEMORY
2015-02-12 10:13:27,594 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 6467 bytes from map-output for attempt_local8313517_0003_m_000000_0
2015-02-12 10:13:27,595 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 6467, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->6467
2015-02-12 10:13:27,595 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:27,596 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:27,596 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:27,598 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:27,598 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 10:13:27,600 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 6467 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:27,601 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 6471 bytes from disk
2015-02-12 10:13:27,601 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:27,601 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:27,601 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 10:13:27,602 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:27,602 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:27,602 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:27,613 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2015-02-12 10:13:27,613 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite"]
2015-02-12 10:13:27,634 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local8313517_0003_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:27,635 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:27,635 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local8313517_0003_r_000000_0 is allowed to commit now
2015-02-12 10:13:27,636 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local8313517_0003_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite/_temporary/0/task_local8313517_0003_r_000000
2015-02-12 10:13:27,638 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:27,638 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local8313517_0003_r_000000_0' done.
2015-02-12 10:13:27,638 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local8313517_0003_r_000000_0
2015-02-12 10:13:27,638 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:27,673 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite/_temporary
2015-02-12 10:13:27,718 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:27,761 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:27,763 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/composite
2015-02-12 10:13:27,800 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 10:13:27,800 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 10:13:27,824 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:27,829 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:27,853 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 10:13:27,863 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] starting
2015-02-12 10:13:27,864 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:27,864 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson]  sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite"]
2015-02-12 10:13:27,864 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson]  parallel execution is enabled: false
2015-02-12 10:13:27,864 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson]  starting jobs: 3
2015-02-12 10:13:27,864 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson]  allocating threads: 1
2015-02-12 10:13:27,865 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (1/3)
2015-02-12 10:13:27,866 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:27,867 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:27,898 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:27,926 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:27,948 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local1379507811_0004
2015-02-12 10:13:28,039 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:28,040 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:28,040 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:28,040 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local1379507811_0004
2015-02-12 10:13:28,040 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2015-02-12 10:13:28,042 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:28,042 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1379507811_0004_m_000000_0
2015-02-12 10:13:28,044 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:28,044 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:28,046 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt
2015-02-12 10:13:28,046 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1e16c33f
2015-02-12 10:13:28,048 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:28,111 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:28,112 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:28,112 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:28,112 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:28,112 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:28,113 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:28,114 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:28,114 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:28,124 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:28,125 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 10:13:28,129 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:28,130 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:28,130 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:28,130 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 10:13:28,130 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 10:13:28,133 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:28,134 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1379507811_0004_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:28,137 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt:0+828
2015-02-12 10:13:28,137 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1379507811_0004_m_000000_0' done.
2015-02-12 10:13:28,137 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1379507811_0004_m_000000_0
2015-02-12 10:13:28,137 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:28,138 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:28,138 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1379507811_0004_r_000000_0
2015-02-12 10:13:28,140 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:28,140 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:28,140 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@3d090e84
2015-02-12 10:13:28,141 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:28,141 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1379507811_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:28,143 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#4 about to shuffle output of map attempt_local1379507811_0004_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 10:13:28,143 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local1379507811_0004_m_000000_0
2015-02-12 10:13:28,144 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 10:13:28,144 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:28,145 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:28,145 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:28,146 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:28,146 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:28,148 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:28,149 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 1822 bytes from disk
2015-02-12 10:13:28,149 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:28,149 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:28,149 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:28,150 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:28,150 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:28,150 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:28,160 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 10:13:28,160 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][3500661422/pearson/]
2015-02-12 10:13:28,170 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:28,170 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:28,196 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1379507811_0004_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:28,197 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:28,198 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1379507811_0004_r_000000_0 is allowed to commit now
2015-02-12 10:13:28,198 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1379507811_0004_r_000000_0' to file:/tmp/hadoop-soberoi/3500661422_pearson_A4B2F87E341C45729519A726B681B477/_temporary/0/task_local1379507811_0004_r_000000
2015-02-12 10:13:28,200 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:28,200 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1379507811_0004_r_000000_0' done.
2015-02-12 10:13:28,200 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1379507811_0004_r_000000_0
2015-02-12 10:13:28,200 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:28,218 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (2/3)
2015-02-12 10:13:28,218 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:28,220 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:28,267 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:28,295 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:28,308 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:28,308 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:28,330 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local644209429_0005
2015-02-12 10:13:28,415 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:28,415 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:28,415 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local644209429_0005
2015-02-12 10:13:28,416 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:28,416 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2015-02-12 10:13:28,418 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:28,418 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local644209429_0005_m_000000_0
2015-02-12 10:13:28,421 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:28,422 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:28,423 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/3500661422_pearson_A4B2F87E341C45729519A726B681B477/part-00000
2015-02-12 10:13:28,423 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@64f62484
2015-02-12 10:13:28,425 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:28,486 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:28,486 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:28,486 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:28,486 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:28,487 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:28,487 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:28,488 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:28,488 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:28,496 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][3500661422/pearson/]
2015-02-12 10:13:28,496 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2015-02-12 10:13:28,510 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:28,510 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:28,511 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:28,511 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 10:13:28,511 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 10:13:28,522 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:28,524 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local644209429_0005_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:28,526 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/3500661422_pearson_A4B2F87E341C45729519A726B681B477/part-00000:0+13816
2015-02-12 10:13:28,526 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local644209429_0005_m_000000_0' done.
2015-02-12 10:13:28,526 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local644209429_0005_m_000000_0
2015-02-12 10:13:28,527 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:28,527 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:28,527 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local644209429_0005_r_000000_0
2015-02-12 10:13:28,529 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:28,529 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:28,529 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@39253c7f
2015-02-12 10:13:28,530 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:28,531 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local644209429_0005_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:28,532 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#5 about to shuffle output of map attempt_local644209429_0005_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 10:13:28,533 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local644209429_0005_m_000000_0
2015-02-12 10:13:28,533 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 10:13:28,535 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:28,535 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:28,536 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:28,537 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:28,537 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:28,540 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:28,540 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 13458 bytes from disk
2015-02-12 10:13:28,541 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:28,541 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:28,541 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:28,542 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:28,542 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:28,542 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:28,550 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2015-02-12 10:13:28,550 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][5353596649/pearson/]
2015-02-12 10:13:28,577 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local644209429_0005_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:28,579 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:28,579 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local644209429_0005_r_000000_0 is allowed to commit now
2015-02-12 10:13:28,581 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local644209429_0005_r_000000_0' to file:/tmp/hadoop-soberoi/5353596649_pearson_3FD1C687FDF74C6EBD4D259A835EC0D8/_temporary/0/task_local644209429_0005_r_000000
2015-02-12 10:13:28,582 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:28,582 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local644209429_0005_r_000000_0' done.
2015-02-12 10:13:28,583 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local644209429_0005_r_000000_0
2015-02-12 10:13:28,583 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:28,604 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (3/3) ...latform/pearson/composite
2015-02-12 10:13:28,605 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:28,606 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:28,655 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:28,677 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:28,692 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:28,692 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:28,867 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local330770689_0006
2015-02-12 10:13:28,937 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:28,937 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:28,937 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:28,937 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local330770689_0006
2015-02-12 10:13:28,938 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2015-02-12 10:13:28,940 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:28,940 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local330770689_0006_m_000000_0
2015-02-12 10:13:28,941 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:28,941 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:28,943 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/5353596649_pearson_3FD1C687FDF74C6EBD4D259A835EC0D8/part-00000
2015-02-12 10:13:28,943 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3a763d2f
2015-02-12 10:13:28,944 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:28,962 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:28,962 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:28,962 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:28,962 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:28,963 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:28,964 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:28,964 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:28,964 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:28,972 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][5353596649/pearson/]
2015-02-12 10:13:28,972 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2015-02-12 10:13:28,985 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:28,985 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:28,986 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:28,986 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 6291; bufvoid = 104857600
2015-02-12 10:13:28,986 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 10:13:28,990 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:28,991 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local330770689_0006_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:28,993 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/5353596649_pearson_3FD1C687FDF74C6EBD4D259A835EC0D8/part-00000:0+6943
2015-02-12 10:13:28,993 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local330770689_0006_m_000000_0' done.
2015-02-12 10:13:28,993 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local330770689_0006_m_000000_0
2015-02-12 10:13:28,994 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:28,994 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:28,994 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local330770689_0006_r_000000_0
2015-02-12 10:13:28,996 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:28,997 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:28,997 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5238dae8
2015-02-12 10:13:28,999 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:28,999 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local330770689_0006_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:29,001 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#6 about to shuffle output of map attempt_local330770689_0006_m_000000_0 decomp: 6467 len: 6471 to MEMORY
2015-02-12 10:13:29,001 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 6467 bytes from map-output for attempt_local330770689_0006_m_000000_0
2015-02-12 10:13:29,002 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 6467, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->6467
2015-02-12 10:13:29,002 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:29,003 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,003 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:29,004 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:29,004 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 10:13:29,006 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 6467 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:29,007 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 6471 bytes from disk
2015-02-12 10:13:29,007 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:29,007 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:29,007 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 10:13:29,008 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,008 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:29,008 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:29,017 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2015-02-12 10:13:29,017 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite"]
2015-02-12 10:13:29,049 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local330770689_0006_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:29,051 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,051 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local330770689_0006_r_000000_0 is allowed to commit now
2015-02-12 10:13:29,052 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local330770689_0006_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite/_temporary/0/task_local330770689_0006_r_000000
2015-02-12 10:13:29,053 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:29,053 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local330770689_0006_r_000000_0' done.
2015-02-12 10:13:29,053 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local330770689_0006_r_000000_0
2015-02-12 10:13:29,053 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:29,085 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite/_temporary
2015-02-12 10:13:29,129 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:29,172 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:29,174 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output//hadoop2-mr1/distanceusecaseplatform/pearson/composite
2015-02-12 10:13:29,209 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 10:13:29,209 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 10:13:29,232 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:29,235 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:29,260 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 10:13:29,276 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting
2015-02-12 10:13:29,276 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:29,276 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long"]
2015-02-12 10:13:29,276 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  parallel execution is enabled: false
2015-02-12 10:13:29,276 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  starting jobs: 3
2015-02-12 10:13:29,277 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  allocating threads: 1
2015-02-12 10:13:29,277 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2015-02-12 10:13:29,278 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:29,279 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:29,311 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:29,338 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:29,357 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local868261734_0007
2015-02-12 10:13:29,438 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:29,438 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:29,439 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:29,438 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local868261734_0007
2015-02-12 10:13:29,439 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:29,440 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:29,441 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local868261734_0007_m_000000_0
2015-02-12 10:13:29,442 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:29,442 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:29,443 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt
2015-02-12 10:13:29,444 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2227fdd6
2015-02-12 10:13:29,445 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:29,458 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:29,458 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:29,458 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:29,458 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:29,458 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:29,459 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:29,459 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:29,459 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:29,467 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:29,467 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 10:13:29,471 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:29,471 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:29,471 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:29,471 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 10:13:29,471 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 10:13:29,473 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:29,475 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local868261734_0007_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:29,477 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt:0+828
2015-02-12 10:13:29,477 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local868261734_0007_m_000000_0' done.
2015-02-12 10:13:29,477 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local868261734_0007_m_000000_0
2015-02-12 10:13:29,477 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:29,478 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:29,478 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local868261734_0007_r_000000_0
2015-02-12 10:13:29,480 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:29,480 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:29,480 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@78721257
2015-02-12 10:13:29,480 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:29,481 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local868261734_0007_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:29,482 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#7 about to shuffle output of map attempt_local868261734_0007_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 10:13:29,483 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local868261734_0007_m_000000_0
2015-02-12 10:13:29,483 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 10:13:29,484 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:29,484 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,485 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:29,487 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:29,487 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:29,488 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:29,488 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 1822 bytes from disk
2015-02-12 10:13:29,488 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:29,488 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:29,489 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:29,489 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,490 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:29,490 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:29,496 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 10:13:29,496 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][9995030059/euclidean/]
2015-02-12 10:13:29,502 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:29,502 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:29,523 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local868261734_0007_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:29,524 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,524 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local868261734_0007_r_000000_0 is allowed to commit now
2015-02-12 10:13:29,526 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local868261734_0007_r_000000_0' to file:/tmp/hadoop-soberoi/9995030059_euclidean_12359281ACE149D9995D30FFBF5D0DC3/_temporary/0/task_local868261734_0007_r_000000
2015-02-12 10:13:29,527 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:29,527 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local868261734_0007_r_000000_0' done.
2015-02-12 10:13:29,527 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local868261734_0007_r_000000_0
2015-02-12 10:13:29,527 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:29,543 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2015-02-12 10:13:29,544 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:29,545 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:29,581 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:29,598 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:29,608 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:29,608 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:29,615 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local2020071627_0008
2015-02-12 10:13:29,692 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:29,692 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:29,692 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local2020071627_0008
2015-02-12 10:13:29,692 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:29,692 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:29,697 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:29,697 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local2020071627_0008_m_000000_0
2015-02-12 10:13:29,698 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:29,698 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:29,699 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/9995030059_euclidean_12359281ACE149D9995D30FFBF5D0DC3/part-00000
2015-02-12 10:13:29,700 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@a1ed4d1
2015-02-12 10:13:29,701 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:29,748 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:29,749 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:29,749 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:29,749 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:29,749 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:29,750 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:29,750 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:29,750 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:29,757 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][9995030059/euclidean/]
2015-02-12 10:13:29,757 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 10:13:29,764 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:29,764 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:29,764 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:29,764 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 10:13:29,764 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 10:13:29,771 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:29,773 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local2020071627_0008_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:29,774 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/9995030059_euclidean_12359281ACE149D9995D30FFBF5D0DC3/part-00000:0+13816
2015-02-12 10:13:29,775 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local2020071627_0008_m_000000_0' done.
2015-02-12 10:13:29,775 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local2020071627_0008_m_000000_0
2015-02-12 10:13:29,775 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:29,776 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:29,776 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local2020071627_0008_r_000000_0
2015-02-12 10:13:29,778 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:29,778 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:29,778 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@65e6cf27
2015-02-12 10:13:29,779 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:29,779 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local2020071627_0008_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:29,781 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#8 about to shuffle output of map attempt_local2020071627_0008_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 10:13:29,781 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local2020071627_0008_m_000000_0
2015-02-12 10:13:29,782 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 10:13:29,782 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:29,783 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,783 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:29,784 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:29,784 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:29,789 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:29,790 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 13458 bytes from disk
2015-02-12 10:13:29,790 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:29,790 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:29,790 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:29,791 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,791 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:29,791 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:29,798 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 10:13:29,799 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][3952442989/euclidean/]
2015-02-12 10:13:29,831 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local2020071627_0008_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:29,833 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:29,836 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local2020071627_0008_r_000000_0 is allowed to commit now
2015-02-12 10:13:29,837 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local2020071627_0008_r_000000_0' to file:/tmp/hadoop-soberoi/3952442989_euclidean_AD795E5231E64692B3BEBA186B0085D0/_temporary/0/task_local2020071627_0008_r_000000
2015-02-12 10:13:29,838 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:29,838 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local2020071627_0008_r_000000_0' done.
2015-02-12 10:13:29,839 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local2020071627_0008_r_000000_0
2015-02-12 10:13:29,839 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:29,864 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...seplatform/euclidean/long
2015-02-12 10:13:29,864 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:29,865 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:29,916 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:29,934 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:29,943 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:29,943 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:29,948 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local899561788_0009
2015-02-12 10:13:30,051 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:30,051 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:30,051 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local899561788_0009
2015-02-12 10:13:30,052 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:30,052 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:30,054 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:30,054 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local899561788_0009_m_000000_0
2015-02-12 10:13:30,055 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:30,055 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:30,056 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/3952442989_euclidean_AD795E5231E64692B3BEBA186B0085D0/part-00000
2015-02-12 10:13:30,056 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@38ded3e6
2015-02-12 10:13:30,057 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:30,070 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:30,070 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:30,070 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:30,070 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:30,070 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:30,071 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:30,071 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:30,071 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:30,077 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][3952442989/euclidean/]
2015-02-12 10:13:30,077 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 10:13:30,081 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:30,081 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:30,081 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:30,081 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 7074; bufvoid = 104857600
2015-02-12 10:13:30,081 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 10:13:30,084 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:30,086 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local899561788_0009_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:30,088 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/3952442989_euclidean_AD795E5231E64692B3BEBA186B0085D0/part-00000:0+7726
2015-02-12 10:13:30,088 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local899561788_0009_m_000000_0' done.
2015-02-12 10:13:30,088 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local899561788_0009_m_000000_0
2015-02-12 10:13:30,088 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:30,089 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:30,089 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local899561788_0009_r_000000_0
2015-02-12 10:13:30,091 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:30,091 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:30,091 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@52fc275f
2015-02-12 10:13:30,091 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:30,092 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local899561788_0009_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:30,094 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#9 about to shuffle output of map attempt_local899561788_0009_m_000000_0 decomp: 7250 len: 7254 to MEMORY
2015-02-12 10:13:30,094 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 7250 bytes from map-output for attempt_local899561788_0009_m_000000_0
2015-02-12 10:13:30,094 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 7250, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->7250
2015-02-12 10:13:30,095 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:30,095 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,096 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:30,097 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:30,097 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 10:13:30,099 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 7250 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:30,099 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 7254 bytes from disk
2015-02-12 10:13:30,100 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:30,100 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:30,100 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 10:13:30,101 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,101 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:30,101 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:30,106 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 10:13:30,106 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long"]
2015-02-12 10:13:30,116 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local899561788_0009_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:30,117 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,117 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local899561788_0009_r_000000_0 is allowed to commit now
2015-02-12 10:13:30,118 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local899561788_0009_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long/_temporary/0/task_local899561788_0009_r_000000
2015-02-12 10:13:30,119 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:30,119 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local899561788_0009_r_000000_0' done.
2015-02-12 10:13:30,119 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local899561788_0009_r_000000_0
2015-02-12 10:13:30,119 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:30,140 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long/_temporary
2015-02-12 10:13:30,174 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:30,202 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:30,204 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/long
2015-02-12 10:13:30,227 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 10:13:30,228 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 10:13:30,246 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:30,248 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:30,264 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 10:13:30,272 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting
2015-02-12 10:13:30,273 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:30,273 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short"]
2015-02-12 10:13:30,273 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  parallel execution is enabled: false
2015-02-12 10:13:30,273 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  starting jobs: 3
2015-02-12 10:13:30,273 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean]  allocating threads: 1
2015-02-12 10:13:30,274 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2015-02-12 10:13:30,274 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:30,275 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:30,306 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:30,330 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:30,347 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local794596702_0010
2015-02-12 10:13:30,417 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:30,418 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:30,418 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local794596702_0010
2015-02-12 10:13:30,418 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:30,418 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:30,420 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:30,420 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local794596702_0010_m_000000_0
2015-02-12 10:13:30,422 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:30,422 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:30,423 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt
2015-02-12 10:13:30,424 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6d6e70aa
2015-02-12 10:13:30,425 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:30,444 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:30,444 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:30,445 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:30,445 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:30,445 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:30,449 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:30,449 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:30,450 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:30,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt"]
2015-02-12 10:13:30,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 10:13:30,462 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:30,462 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:30,462 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:30,462 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 10:13:30,462 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 10:13:30,468 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:30,469 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local794596702_0010_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:30,471 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/classes/test/data/critics.txt:0+828
2015-02-12 10:13:30,471 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local794596702_0010_m_000000_0' done.
2015-02-12 10:13:30,472 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local794596702_0010_m_000000_0
2015-02-12 10:13:30,472 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:30,472 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:30,472 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local794596702_0010_r_000000_0
2015-02-12 10:13:30,475 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:30,475 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:30,475 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7c7996db
2015-02-12 10:13:30,476 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:30,476 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local794596702_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:30,477 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#10 about to shuffle output of map attempt_local794596702_0010_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 10:13:30,478 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local794596702_0010_m_000000_0
2015-02-12 10:13:30,478 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 10:13:30,478 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:30,479 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,479 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:30,480 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:30,481 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:30,482 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:30,482 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 1822 bytes from disk
2015-02-12 10:13:30,483 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:30,483 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:30,483 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 10:13:30,484 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,484 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:30,484 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:30,489 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 10:13:30,489 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][232427618/euclidean/]
2015-02-12 10:13:30,496 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:30,496 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 10:13:30,515 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local794596702_0010_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:30,516 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,516 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local794596702_0010_r_000000_0 is allowed to commit now
2015-02-12 10:13:30,517 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local794596702_0010_r_000000_0' to file:/tmp/hadoop-soberoi/232427618_euclidean_57130DDB6B254B0992DDFC434EA54426/_temporary/0/task_local794596702_0010_r_000000
2015-02-12 10:13:30,519 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:30,519 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local794596702_0010_r_000000_0' done.
2015-02-12 10:13:30,519 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local794596702_0010_r_000000_0
2015-02-12 10:13:30,522 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:30,545 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2015-02-12 10:13:30,545 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:30,546 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:30,596 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:30,614 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:30,622 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:30,622 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:30,627 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local1898248771_0011
2015-02-12 10:13:30,703 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:30,703 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local1898248771_0011
2015-02-12 10:13:30,703 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:30,704 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:30,704 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:30,707 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:30,708 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1898248771_0011_m_000000_0
2015-02-12 10:13:30,709 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:30,709 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:30,710 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/232427618_euclidean_57130DDB6B254B0992DDFC434EA54426/part-00000
2015-02-12 10:13:30,711 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3fc12084
2015-02-12 10:13:30,712 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:30,725 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:30,725 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:30,725 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:30,725 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:30,725 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:30,726 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:30,726 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:30,726 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:30,732 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][232427618/euclidean/]
2015-02-12 10:13:30,732 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 10:13:30,741 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:30,742 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:30,742 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:30,742 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 10:13:30,742 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 10:13:30,752 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:30,762 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1898248771_0011_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:30,770 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/232427618_euclidean_57130DDB6B254B0992DDFC434EA54426/part-00000:0+13816
2015-02-12 10:13:30,770 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1898248771_0011_m_000000_0' done.
2015-02-12 10:13:30,770 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1898248771_0011_m_000000_0
2015-02-12 10:13:30,771 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:30,776 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:30,776 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1898248771_0011_r_000000_0
2015-02-12 10:13:30,781 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:30,781 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:30,781 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@47825164
2015-02-12 10:13:30,784 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:30,788 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1898248771_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:30,791 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#11 about to shuffle output of map attempt_local1898248771_0011_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 10:13:30,791 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local1898248771_0011_m_000000_0
2015-02-12 10:13:30,792 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 10:13:30,794 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:30,795 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,795 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:30,797 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:30,799 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:30,808 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:30,808 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 13458 bytes from disk
2015-02-12 10:13:30,808 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:30,808 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:30,809 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 10:13:30,809 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,809 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:30,809 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:30,816 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 10:13:30,816 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8095896084/euclidean/]
2015-02-12 10:13:30,846 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1898248771_0011_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:30,847 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:30,848 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1898248771_0011_r_000000_0 is allowed to commit now
2015-02-12 10:13:30,850 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1898248771_0011_r_000000_0' to file:/tmp/hadoop-soberoi/8095896084_euclidean_0F2C35B73BF24539A114E7E5AE489198/_temporary/0/task_local1898248771_0011_r_000000
2015-02-12 10:13:30,852 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:30,852 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1898248771_0011_r_000000_0' done.
2015-02-12 10:13:30,853 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1898248771_0011_r_000000_0
2015-02-12 10:13:30,853 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:30,877 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...eplatform/euclidean/short
2015-02-12 10:13:30,877 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:30,878 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 10:13:30,916 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:30,938 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(494)) - number of splits:1
2015-02-12 10:13:30,947 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 10:13:30,947 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1051)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 10:13:30,954 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(583)) - Submitting tokens for job: job_local319645765_0012
2015-02-12 10:13:31,024 INFO  mapreduce.Job (Job.java:submit(1300)) - The url to track the job: http://localhost:8080/
2015-02-12 10:13:31,024 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 10:13:31,024 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 10:13:31,024 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local319645765_0012
2015-02-12 10:13:31,024 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 10:13:31,027 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 10:13:31,027 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local319645765_0012_m_000000_0
2015-02-12 10:13:31,028 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:31,028 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:31,029 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/8095896084_euclidean_0F2C35B73BF24539A114E7E5AE489198/part-00000
2015-02-12 10:13:31,030 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@5ef3a7e
2015-02-12 10:13:31,031 INFO  mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 10:13:31,044 INFO  mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 10:13:31,044 INFO  mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 10:13:31,044 INFO  mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 10:13:31,045 INFO  mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 10:13:31,045 INFO  mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 10:13:31,045 INFO  mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 10:13:31,045 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 10:13:31,046 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 10:13:31,051 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8095896084/euclidean/]
2015-02-12 10:13:31,052 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 10:13:31,055 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-12 10:13:31,056 INFO  mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 10:13:31,056 INFO  mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 10:13:31,056 INFO  mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 7074; bufvoid = 104857600
2015-02-12 10:13:31,056 INFO  mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 10:13:31,058 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 10:13:31,059 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local319645765_0012_m_000000_0 is done. And is in the process of committing
2015-02-12 10:13:31,061 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/8095896084_euclidean_0F2C35B73BF24539A114E7E5AE489198/part-00000:0+7726
2015-02-12 10:13:31,061 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local319645765_0012_m_000000_0' done.
2015-02-12 10:13:31,061 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local319645765_0012_m_000000_0
2015-02-12 10:13:31,065 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 10:13:31,067 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 10:13:31,067 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local319645765_0012_r_000000_0
2015-02-12 10:13:31,069 INFO  util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 10:13:31,069 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : null
2015-02-12 10:13:31,069 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@28aff069
2015-02-12 10:13:31,070 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(196)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 10:13:31,072 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local319645765_0012_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 10:13:31,073 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#12 about to shuffle output of map attempt_local319645765_0012_m_000000_0 decomp: 7250 len: 7254 to MEMORY
2015-02-12 10:13:31,073 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 7250 bytes from map-output for attempt_local319645765_0012_m_000000_0
2015-02-12 10:13:31,074 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(314)) - closeInMemoryFile -> map-output of size: 7250, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->7250
2015-02-12 10:13:31,074 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 10:13:31,075 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:31,075 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(674)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 10:13:31,076 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:31,076 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 10:13:31,078 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(751)) - Merged 1 segments, 7250 bytes to disk to satisfy reduce memory limit
2015-02-12 10:13:31,078 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(781)) - Merging 1 files, 7254 bytes from disk
2015-02-12 10:13:31,078 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(796)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 10:13:31,078 INFO  mapred.Merger (Merger.java:merge(597)) - Merging 1 sorted segments
2015-02-12 10:13:31,079 INFO  mapred.Merger (Merger.java:merge(696)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 10:13:31,079 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:31,080 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 10:13:31,080 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 10:13:31,086 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 10:13:31,087 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short"]
2015-02-12 10:13:31,099 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local319645765_0012_r_000000_0 is done. And is in the process of committing
2015-02-12 10:13:31,100 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 10:13:31,100 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local319645765_0012_r_000000_0 is allowed to commit now
2015-02-12 10:13:31,101 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local319645765_0012_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short/_temporary/0/task_local319645765_0012_r_000000
2015-02-12 10:13:31,102 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 10:13:31,102 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local319645765_0012_r_000000_0' done.
2015-02-12 10:13:31,102 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local319645765_0012_r_000000_0
2015-02-12 10:13:31,103 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 10:13:31,121 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short/_temporary
2015-02-12 10:13:31,147 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:31,176 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 10:13:31,177 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/horton/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/short