2015-02-12 15:00:08,358 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-02-12 15:00:08,393 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-02-12 15:00:08,394 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.DistanceUseCasePlatformTest
2015-02-12 15:00:08,407 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-02-12 15:00:08,848 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 15:00:09,042 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 15:00:09,045 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 15:00:09,060 INFO property.AppProps (AppProps.java:getAppID(169)) - using app.id: 81B9E7A86B5E4CB59ACCBA5172E377CB
2015-02-12 15:00:09,150 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:09,181 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:09,289 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 15:00:09,346 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 2.6.3
2015-02-12 15:00:09,348 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting
2015-02-12 15:00:09,349 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:09,350 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite"]
2015-02-12 15:00:09,350 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] parallel execution is enabled: false
2015-02-12 15:00:09,351 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting jobs: 3
2015-02-12 15:00:09,351 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] allocating threads: 1
2015-02-12 15:00:09,353 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2015-02-12 15:00:09,374 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2015-02-12 15:00:09,376 INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2015-02-12 15:00:09,392 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:09,593 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:09,623 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:09,781 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local641949328_0001
2015-02-12 15:00:09,803 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi641949328/.staging/job_local641949328_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:09,809 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi641949328/.staging/job_local641949328_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:09,945 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local641949328_0001/job_local641949328_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:09,951 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local641949328_0001/job_local641949328_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:09,960 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:09,961 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:09,962 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local641949328_0001
2015-02-12 15:00:09,962 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:09,963 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:09,978 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:09,980 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local641949328_0001_m_000000_0
2015-02-12 15:00:10,006 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:10,007 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:10,017 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt
2015-02-12 15:00:10,018 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@701c415b
2015-02-12 15:00:10,027 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:10,103 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:10,103 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:10,103 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:10,103 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:10,103 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:10,123 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:10,126 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:10,126 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:10,177 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2015-02-12 15:00:10,191 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:10,191 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 15:00:10,202 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:10,202 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:10,202 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:10,203 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 15:00:10,203 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 15:00:10,211 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:10,216 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local641949328_0001_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:10,229 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt:0+828
2015-02-12 15:00:10,230 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local641949328_0001_m_000000_0' done.
2015-02-12 15:00:10,230 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local641949328_0001_m_000000_0
2015-02-12 15:00:10,231 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:10,233 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:10,234 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local641949328_0001_r_000000_0
2015-02-12 15:00:10,240 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:10,241 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:10,243 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5d834c31
2015-02-12 15:00:10,259 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:10,263 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local641949328_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:10,294 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#1 about to shuffle output of map attempt_local641949328_0001_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 15:00:10,300 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local641949328_0001_m_000000_0
2015-02-12 15:00:10,334 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 15:00:10,336 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:10,337 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:10,337 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:10,344 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:10,344 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:10,347 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:10,348 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 1822 bytes from disk
2015-02-12 15:00:10,349 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:10,349 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:10,349 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:10,350 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:10,351 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:10,351 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:10,368 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 15:00:10,368 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1887266050/euclidean/]
2015-02-12 15:00:10,403 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:10,403 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:10,459 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local641949328_0001_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:10,461 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:10,461 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local641949328_0001_r_000000_0 is allowed to commit now
2015-02-12 15:00:10,462 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local641949328_0001_r_000000_0' to file:/tmp/hadoop-soberoi/1887266050_euclidean_3B66D200C4E340A49215DDBF38E789D1/_temporary/0/task_local641949328_0001_r_000000
2015-02-12 15:00:10,463 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:10,464 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local641949328_0001_r_000000_0' done.
2015-02-12 15:00:10,465 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local641949328_0001_r_000000_0
2015-02-12 15:00:10,467 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:10,512 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2015-02-12 15:00:10,513 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:10,514 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:10,568 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:10,594 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:10,608 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:10,609 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:10,624 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local1278852763_0002
2015-02-12 15:00:10,644 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1278852763/.staging/job_local1278852763_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:10,645 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1278852763/.staging/job_local1278852763_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:10,718 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1278852763_0002/job_local1278852763_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:10,720 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1278852763_0002/job_local1278852763_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:10,721 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:10,721 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:10,721 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:10,722 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local1278852763_0002
2015-02-12 15:00:10,722 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:10,723 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:10,723 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1278852763_0002_m_000000_0
2015-02-12 15:00:10,725 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:10,725 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:10,727 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/1887266050_euclidean_3B66D200C4E340A49215DDBF38E789D1/part-00000
2015-02-12 15:00:10,727 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@269df39
2015-02-12 15:00:10,734 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:10,783 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:10,783 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:10,784 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:10,784 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:10,784 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:10,785 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:10,785 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:10,785 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:10,796 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1887266050/euclidean/]
2015-02-12 15:00:10,796 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 15:00:10,814 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:10,815 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:10,815 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:10,815 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 15:00:10,815 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 15:00:10,843 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:10,845 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1278852763_0002_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:10,847 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/1887266050_euclidean_3B66D200C4E340A49215DDBF38E789D1/part-00000:0+13816
2015-02-12 15:00:10,848 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1278852763_0002_m_000000_0' done.
2015-02-12 15:00:10,849 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1278852763_0002_m_000000_0
2015-02-12 15:00:10,849 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:10,849 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:10,849 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1278852763_0002_r_000000_0
2015-02-12 15:00:10,851 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:10,852 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:10,852 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7b0036f2
2015-02-12 15:00:10,852 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:10,853 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1278852763_0002_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:10,854 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#2 about to shuffle output of map attempt_local1278852763_0002_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 15:00:10,855 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local1278852763_0002_m_000000_0
2015-02-12 15:00:10,855 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 15:00:10,856 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:10,857 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:10,857 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:10,860 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:10,860 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:10,864 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:10,865 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 13458 bytes from disk
2015-02-12 15:00:10,865 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:10,865 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:10,881 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:10,882 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:10,883 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:10,884 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:10,893 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 15:00:10,894 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6128261851/euclidean/]
2015-02-12 15:00:10,919 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1278852763_0002_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:10,920 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:10,921 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local1278852763_0002_r_000000_0 is allowed to commit now
2015-02-12 15:00:10,922 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1278852763_0002_r_000000_0' to file:/tmp/hadoop-soberoi/6128261851_euclidean_95EE12CD631D448995703CAD52CB0453/_temporary/0/task_local1278852763_0002_r_000000
2015-02-12 15:00:10,924 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:10,925 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1278852763_0002_r_000000_0' done.
2015-02-12 15:00:10,925 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1278852763_0002_r_000000_0
2015-02-12 15:00:10,926 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:10,956 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...tform/euclidean/composite
2015-02-12 15:00:10,957 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:10,958 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:11,011 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:11,055 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:11,071 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:11,072 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:11,121 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local944352430_0003
2015-02-12 15:00:11,149 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi944352430/.staging/job_local944352430_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:11,152 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi944352430/.staging/job_local944352430_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:11,241 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local944352430_0003/job_local944352430_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:11,245 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local944352430_0003/job_local944352430_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:11,247 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:11,247 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:11,247 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local944352430_0003
2015-02-12 15:00:11,248 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:11,249 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:11,252 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:11,252 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local944352430_0003_m_000000_0
2015-02-12 15:00:11,254 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:11,255 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:11,258 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/6128261851_euclidean_95EE12CD631D448995703CAD52CB0453/part-00000
2015-02-12 15:00:11,258 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1edec59c
2015-02-12 15:00:11,260 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:11,324 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:11,325 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:11,325 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:11,326 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:11,326 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:11,328 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:11,329 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:11,329 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:11,343 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6128261851/euclidean/]
2015-02-12 15:00:11,344 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2015-02-12 15:00:11,351 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:11,351 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:11,351 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:11,352 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 6291; bufvoid = 104857600
2015-02-12 15:00:11,352 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 15:00:11,359 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:11,365 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local944352430_0003_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:11,366 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/6128261851_euclidean_95EE12CD631D448995703CAD52CB0453/part-00000:0+6943
2015-02-12 15:00:11,367 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local944352430_0003_m_000000_0' done.
2015-02-12 15:00:11,367 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local944352430_0003_m_000000_0
2015-02-12 15:00:11,367 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:11,368 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:11,368 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local944352430_0003_r_000000_0
2015-02-12 15:00:11,369 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:11,370 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:11,370 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@22981ee3
2015-02-12 15:00:11,370 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:11,371 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local944352430_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:11,372 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#3 about to shuffle output of map attempt_local944352430_0003_m_000000_0 decomp: 6467 len: 6471 to MEMORY
2015-02-12 15:00:11,373 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 6467 bytes from map-output for attempt_local944352430_0003_m_000000_0
2015-02-12 15:00:11,373 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 6467, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->6467
2015-02-12 15:00:11,373 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:11,374 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:11,374 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:11,376 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:11,376 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 15:00:11,379 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 6467 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:11,379 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 6471 bytes from disk
2015-02-12 15:00:11,380 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:11,380 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:11,380 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 15:00:11,381 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:11,381 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:11,381 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:11,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2015-02-12 15:00:11,392 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite"]
2015-02-12 15:00:11,424 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local944352430_0003_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:11,425 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:11,425 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local944352430_0003_r_000000_0 is allowed to commit now
2015-02-12 15:00:11,426 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local944352430_0003_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite/_temporary/0/task_local944352430_0003_r_000000
2015-02-12 15:00:11,427 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:11,427 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local944352430_0003_r_000000_0' done.
2015-02-12 15:00:11,427 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local944352430_0003_r_000000_0
2015-02-12 15:00:11,428 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:11,457 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite/_temporary
2015-02-12 15:00:11,505 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:11,553 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:11,555 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/composite
2015-02-12 15:00:11,593 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 15:00:11,593 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 15:00:11,614 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:11,621 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:11,650 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 15:00:11,660 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] starting
2015-02-12 15:00:11,660 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:11,661 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite"]
2015-02-12 15:00:11,661 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] parallel execution is enabled: false
2015-02-12 15:00:11,661 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] starting jobs: 3
2015-02-12 15:00:11,661 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pearson] allocating threads: 1
2015-02-12 15:00:11,661 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (1/3)
2015-02-12 15:00:11,662 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:11,664 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:11,707 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:11,756 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:11,783 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local526995755_0004
2015-02-12 15:00:11,810 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi526995755/.staging/job_local526995755_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:11,811 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi526995755/.staging/job_local526995755_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:11,867 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local526995755_0004/job_local526995755_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:11,868 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local526995755_0004/job_local526995755_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:11,868 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:11,869 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local526995755_0004
2015-02-12 15:00:11,869 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2015-02-12 15:00:11,869 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:11,869 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:11,871 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:11,871 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local526995755_0004_m_000000_0
2015-02-12 15:00:11,873 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:11,873 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:11,874 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt
2015-02-12 15:00:11,875 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@158654b4
2015-02-12 15:00:11,877 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:11,913 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:11,913 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:11,914 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:11,914 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:11,914 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:11,915 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:11,915 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:11,915 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:11,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:11,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 15:00:11,929 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:11,929 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:11,929 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:11,929 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 15:00:11,929 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 15:00:11,934 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:11,936 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local526995755_0004_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:11,937 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt:0+828
2015-02-12 15:00:11,938 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local526995755_0004_m_000000_0' done.
2015-02-12 15:00:11,938 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local526995755_0004_m_000000_0
2015-02-12 15:00:11,938 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:11,940 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:11,940 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local526995755_0004_r_000000_0
2015-02-12 15:00:11,944 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:11,944 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:11,945 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7144928c
2015-02-12 15:00:11,945 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:11,946 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local526995755_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:11,948 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#4 about to shuffle output of map attempt_local526995755_0004_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 15:00:11,948 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local526995755_0004_m_000000_0
2015-02-12 15:00:11,948 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 15:00:11,949 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:11,949 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:11,950 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:11,952 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:11,953 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:11,955 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:11,955 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 1822 bytes from disk
2015-02-12 15:00:11,955 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:11,955 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:11,956 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:11,956 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:11,956 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:11,957 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:11,966 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2015-02-12 15:00:11,966 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][573984823/pearson/]
2015-02-12 15:00:11,992 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:11,993 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:12,020 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local526995755_0004_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:12,022 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,023 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local526995755_0004_r_000000_0 is allowed to commit now
2015-02-12 15:00:12,024 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local526995755_0004_r_000000_0' to file:/tmp/hadoop-soberoi/573984823_pearson_6706CA73153D49A69E99A6C459F8EB8B/_temporary/0/task_local526995755_0004_r_000000
2015-02-12 15:00:12,025 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:12,025 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local526995755_0004_r_000000_0' done.
2015-02-12 15:00:12,025 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local526995755_0004_r_000000_0
2015-02-12 15:00:12,025 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:12,054 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (2/3)
2015-02-12 15:00:12,055 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:12,056 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:12,114 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:12,139 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:12,152 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:12,153 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:12,170 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local564992192_0005
2015-02-12 15:00:12,190 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi564992192/.staging/job_local564992192_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:12,191 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi564992192/.staging/job_local564992192_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:12,238 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local564992192_0005/job_local564992192_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:12,239 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local564992192_0005/job_local564992192_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:12,239 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:12,240 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local564992192_0005
2015-02-12 15:00:12,240 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2015-02-12 15:00:12,240 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:12,242 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:12,244 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:12,244 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local564992192_0005_m_000000_0
2015-02-12 15:00:12,246 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:12,246 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:12,247 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/573984823_pearson_6706CA73153D49A69E99A6C459F8EB8B/part-00000
2015-02-12 15:00:12,247 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@493de006
2015-02-12 15:00:12,248 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:12,310 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:12,310 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:12,310 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:12,310 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:12,310 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:12,311 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:12,312 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:12,312 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:12,320 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][573984823/pearson/]
2015-02-12 15:00:12,320 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2015-02-12 15:00:12,336 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:12,337 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:12,337 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:12,337 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 15:00:12,337 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 15:00:12,348 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:12,353 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local564992192_0005_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:12,355 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/573984823_pearson_6706CA73153D49A69E99A6C459F8EB8B/part-00000:0+13816
2015-02-12 15:00:12,355 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local564992192_0005_m_000000_0' done.
2015-02-12 15:00:12,355 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local564992192_0005_m_000000_0
2015-02-12 15:00:12,356 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:12,356 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:12,356 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local564992192_0005_r_000000_0
2015-02-12 15:00:12,359 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:12,360 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:12,360 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@25688092
2015-02-12 15:00:12,362 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:12,363 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local564992192_0005_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:12,366 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#5 about to shuffle output of map attempt_local564992192_0005_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 15:00:12,366 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local564992192_0005_m_000000_0
2015-02-12 15:00:12,367 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 15:00:12,367 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:12,368 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,368 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:12,370 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:12,371 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:12,377 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:12,377 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 13458 bytes from disk
2015-02-12 15:00:12,377 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:12,377 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:12,378 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:12,378 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,378 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:12,379 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:12,386 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2015-02-12 15:00:12,387 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1426441617/pearson/]
2015-02-12 15:00:12,413 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local564992192_0005_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:12,415 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,415 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local564992192_0005_r_000000_0 is allowed to commit now
2015-02-12 15:00:12,416 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local564992192_0005_r_000000_0' to file:/tmp/hadoop-soberoi/1426441617_pearson_BF98BB9D2F3F42DB81713C3F04A6C2BC/_temporary/0/task_local564992192_0005_r_000000
2015-02-12 15:00:12,417 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:12,417 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local564992192_0005_r_000000_0' done.
2015-02-12 15:00:12,417 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local564992192_0005_r_000000_0
2015-02-12 15:00:12,418 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:12,442 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (3/3) ...latform/pearson/composite
2015-02-12 15:00:12,443 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:12,444 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:12,485 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:12,507 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:12,524 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:12,524 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:12,530 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local1480896662_0006
2015-02-12 15:00:12,542 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1480896662/.staging/job_local1480896662_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:12,543 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1480896662/.staging/job_local1480896662_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:12,588 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1480896662_0006/job_local1480896662_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:12,589 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1480896662_0006/job_local1480896662_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:12,589 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:12,590 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local1480896662_0006
2015-02-12 15:00:12,590 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:12,590 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:12,590 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2015-02-12 15:00:12,592 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:12,593 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1480896662_0006_m_000000_0
2015-02-12 15:00:12,594 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:12,594 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:12,595 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/1426441617_pearson_BF98BB9D2F3F42DB81713C3F04A6C2BC/part-00000
2015-02-12 15:00:12,595 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@44939656
2015-02-12 15:00:12,596 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:12,657 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:12,657 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:12,657 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:12,657 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:12,657 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:12,658 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:12,658 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:12,658 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:12,666 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1426441617/pearson/]
2015-02-12 15:00:12,666 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2015-02-12 15:00:12,672 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:12,673 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:12,673 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:12,673 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 6291; bufvoid = 104857600
2015-02-12 15:00:12,673 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 15:00:12,679 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:12,681 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1480896662_0006_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:12,682 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/1426441617_pearson_BF98BB9D2F3F42DB81713C3F04A6C2BC/part-00000:0+6943
2015-02-12 15:00:12,682 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1480896662_0006_m_000000_0' done.
2015-02-12 15:00:12,682 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1480896662_0006_m_000000_0
2015-02-12 15:00:12,683 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:12,683 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:12,683 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1480896662_0006_r_000000_0
2015-02-12 15:00:12,685 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:12,685 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:12,685 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5bd1db4f
2015-02-12 15:00:12,685 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:12,686 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1480896662_0006_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:12,688 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#6 about to shuffle output of map attempt_local1480896662_0006_m_000000_0 decomp: 6467 len: 6471 to MEMORY
2015-02-12 15:00:12,688 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 6467 bytes from map-output for attempt_local1480896662_0006_m_000000_0
2015-02-12 15:00:12,688 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 6467, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->6467
2015-02-12 15:00:12,689 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:12,690 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,690 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:12,692 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:12,692 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 15:00:12,694 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 6467 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:12,694 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 6471 bytes from disk
2015-02-12 15:00:12,694 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:12,695 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:12,695 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2015-02-12 15:00:12,695 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,696 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:12,696 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:12,704 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2015-02-12 15:00:12,704 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite"]
2015-02-12 15:00:12,725 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1480896662_0006_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:12,726 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:12,726 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local1480896662_0006_r_000000_0 is allowed to commit now
2015-02-12 15:00:12,727 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1480896662_0006_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite/_temporary/0/task_local1480896662_0006_r_000000
2015-02-12 15:00:12,728 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:12,728 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1480896662_0006_r_000000_0' done.
2015-02-12 15:00:12,728 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1480896662_0006_r_000000_0
2015-02-12 15:00:12,728 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:12,750 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite/_temporary
2015-02-12 15:00:12,782 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:12,812 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:12,814 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/distanceusecaseplatform/pearson/composite
2015-02-12 15:00:12,840 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 15:00:12,841 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 15:00:12,863 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:12,866 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:12,892 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 15:00:12,908 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting
2015-02-12 15:00:12,908 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:12,908 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long"]
2015-02-12 15:00:12,909 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] parallel execution is enabled: false
2015-02-12 15:00:12,909 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting jobs: 3
2015-02-12 15:00:12,909 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] allocating threads: 1
2015-02-12 15:00:12,910 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2015-02-12 15:00:12,911 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:12,913 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:12,946 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:12,965 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:12,986 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local1919992013_0007
2015-02-12 15:00:13,002 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1919992013/.staging/job_local1919992013_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:13,003 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1919992013/.staging/job_local1919992013_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:13,192 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1919992013_0007/job_local1919992013_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:13,193 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1919992013_0007/job_local1919992013_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:13,193 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:13,194 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local1919992013_0007
2015-02-12 15:00:13,194 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:13,194 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:13,194 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:13,196 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:13,196 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1919992013_0007_m_000000_0
2015-02-12 15:00:13,197 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:13,197 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:13,198 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt
2015-02-12 15:00:13,198 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@182eaa66
2015-02-12 15:00:13,199 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:13,211 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:13,211 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:13,211 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:13,211 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:13,211 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:13,212 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:13,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:13,213 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:13,218 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:13,218 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 15:00:13,221 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:13,221 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:13,221 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:13,221 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 15:00:13,222 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 15:00:13,224 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:13,225 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1919992013_0007_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:13,226 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt:0+828
2015-02-12 15:00:13,227 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1919992013_0007_m_000000_0' done.
2015-02-12 15:00:13,227 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1919992013_0007_m_000000_0
2015-02-12 15:00:13,227 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:13,228 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:13,228 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1919992013_0007_r_000000_0
2015-02-12 15:00:13,230 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:13,230 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:13,230 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1ca530d6
2015-02-12 15:00:13,231 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:13,231 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1919992013_0007_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:13,233 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#7 about to shuffle output of map attempt_local1919992013_0007_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 15:00:13,234 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local1919992013_0007_m_000000_0
2015-02-12 15:00:13,234 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 15:00:13,234 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:13,235 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,235 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:13,237 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:13,237 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:13,239 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:13,239 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 1822 bytes from disk
2015-02-12 15:00:13,239 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:13,239 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:13,239 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:13,240 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,240 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:13,240 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:13,246 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 15:00:13,246 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][5105736382/euclidean/]
2015-02-12 15:00:13,255 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:13,255 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:13,280 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1919992013_0007_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:13,282 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,282 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local1919992013_0007_r_000000_0 is allowed to commit now
2015-02-12 15:00:13,283 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1919992013_0007_r_000000_0' to file:/tmp/hadoop-soberoi/5105736382_euclidean_3F84DFFBE163472C84EFADDF0B107F0D/_temporary/0/task_local1919992013_0007_r_000000
2015-02-12 15:00:13,285 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:13,285 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1919992013_0007_r_000000_0' done.
2015-02-12 15:00:13,285 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1919992013_0007_r_000000_0
2015-02-12 15:00:13,286 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:13,312 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2015-02-12 15:00:13,313 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:13,314 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:13,358 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:13,382 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:13,398 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:13,398 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:13,407 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local788570021_0008
2015-02-12 15:00:13,423 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi788570021/.staging/job_local788570021_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:13,424 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi788570021/.staging/job_local788570021_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:13,469 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local788570021_0008/job_local788570021_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:13,470 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local788570021_0008/job_local788570021_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:13,471 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:13,471 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:13,471 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local788570021_0008
2015-02-12 15:00:13,471 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:13,471 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:13,475 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:13,475 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local788570021_0008_m_000000_0
2015-02-12 15:00:13,477 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:13,477 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:13,479 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/5105736382_euclidean_3F84DFFBE163472C84EFADDF0B107F0D/part-00000
2015-02-12 15:00:13,480 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7c4392c2
2015-02-12 15:00:13,481 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:13,498 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:13,498 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:13,498 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:13,498 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:13,498 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:13,499 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:13,499 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:13,499 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:13,504 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][5105736382/euclidean/]
2015-02-12 15:00:13,504 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 15:00:13,515 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:13,515 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:13,515 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:13,515 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 15:00:13,515 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 15:00:13,523 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:13,525 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local788570021_0008_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:13,527 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/5105736382_euclidean_3F84DFFBE163472C84EFADDF0B107F0D/part-00000:0+13816
2015-02-12 15:00:13,527 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local788570021_0008_m_000000_0' done.
2015-02-12 15:00:13,527 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local788570021_0008_m_000000_0
2015-02-12 15:00:13,527 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:13,528 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:13,528 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local788570021_0008_r_000000_0
2015-02-12 15:00:13,530 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:13,530 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:13,530 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5d4aa6eb
2015-02-12 15:00:13,531 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:13,531 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local788570021_0008_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:13,533 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#8 about to shuffle output of map attempt_local788570021_0008_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 15:00:13,534 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local788570021_0008_m_000000_0
2015-02-12 15:00:13,535 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 15:00:13,536 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:13,537 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,537 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:13,539 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:13,539 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:13,542 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:13,542 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 13458 bytes from disk
2015-02-12 15:00:13,542 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:13,543 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:13,543 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:13,544 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,545 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:13,545 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:13,551 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 15:00:13,551 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][2369149687/euclidean/]
2015-02-12 15:00:13,579 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local788570021_0008_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:13,584 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,584 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local788570021_0008_r_000000_0 is allowed to commit now
2015-02-12 15:00:13,586 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local788570021_0008_r_000000_0' to file:/tmp/hadoop-soberoi/2369149687_euclidean_CD8E01042F834A249416DCA09DBE9119/_temporary/0/task_local788570021_0008_r_000000
2015-02-12 15:00:13,587 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:13,587 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local788570021_0008_r_000000_0' done.
2015-02-12 15:00:13,588 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local788570021_0008_r_000000_0
2015-02-12 15:00:13,588 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:13,614 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...seplatform/euclidean/long
2015-02-12 15:00:13,617 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:13,618 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:13,668 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:13,694 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:13,708 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:13,708 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:13,715 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local246278593_0009
2015-02-12 15:00:13,731 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi246278593/.staging/job_local246278593_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:13,733 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi246278593/.staging/job_local246278593_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:13,786 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local246278593_0009/job_local246278593_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:13,788 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local246278593_0009/job_local246278593_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:13,789 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:13,789 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:13,789 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:13,791 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local246278593_0009
2015-02-12 15:00:13,792 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:13,794 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:13,794 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local246278593_0009_m_000000_0
2015-02-12 15:00:13,797 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:13,797 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:13,799 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/2369149687_euclidean_CD8E01042F834A249416DCA09DBE9119/part-00000
2015-02-12 15:00:13,799 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@10891668
2015-02-12 15:00:13,800 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:13,817 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:13,817 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:13,817 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:13,817 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:13,817 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:13,818 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:13,818 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:13,818 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:13,824 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][2369149687/euclidean/]
2015-02-12 15:00:13,824 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 15:00:13,828 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:13,829 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:13,829 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:13,829 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 7074; bufvoid = 104857600
2015-02-12 15:00:13,829 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 15:00:13,833 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:13,835 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local246278593_0009_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:13,836 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/2369149687_euclidean_CD8E01042F834A249416DCA09DBE9119/part-00000:0+7726
2015-02-12 15:00:13,837 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local246278593_0009_m_000000_0' done.
2015-02-12 15:00:13,837 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local246278593_0009_m_000000_0
2015-02-12 15:00:13,837 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:13,838 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:13,838 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local246278593_0009_r_000000_0
2015-02-12 15:00:13,839 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:13,839 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:13,839 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@3bdfd344
2015-02-12 15:00:13,841 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:13,842 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local246278593_0009_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:13,843 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#9 about to shuffle output of map attempt_local246278593_0009_m_000000_0 decomp: 7250 len: 7254 to MEMORY
2015-02-12 15:00:13,844 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 7250 bytes from map-output for attempt_local246278593_0009_m_000000_0
2015-02-12 15:00:13,844 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 7250, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->7250
2015-02-12 15:00:13,844 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:13,845 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,845 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:13,846 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:13,846 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 15:00:13,848 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 7250 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:13,849 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 7254 bytes from disk
2015-02-12 15:00:13,850 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:13,850 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:13,850 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 15:00:13,851 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,852 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:13,852 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:13,860 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 15:00:13,861 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long"]
2015-02-12 15:00:13,879 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local246278593_0009_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:13,880 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:13,880 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local246278593_0009_r_000000_0 is allowed to commit now
2015-02-12 15:00:13,881 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local246278593_0009_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long/_temporary/0/task_local246278593_0009_r_000000
2015-02-12 15:00:13,882 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:13,883 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local246278593_0009_r_000000_0' done.
2015-02-12 15:00:13,883 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local246278593_0009_r_000000_0
2015-02-12 15:00:13,883 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:13,908 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long/_temporary
2015-02-12 15:00:13,939 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,018 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,021 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/long
2015-02-12 15:00:14,039 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 15:00:14,040 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 15:00:14,053 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:14,055 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:14,073 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 15:00:14,079 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting
2015-02-12 15:00:14,079 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:14,079 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short"]
2015-02-12 15:00:14,079 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] parallel execution is enabled: false
2015-02-12 15:00:14,079 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] starting jobs: 3
2015-02-12 15:00:14,080 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [euclidean] allocating threads: 1
2015-02-12 15:00:14,080 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2015-02-12 15:00:14,080 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:14,081 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:14,112 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,139 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:14,157 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local824009049_0010
2015-02-12 15:00:14,175 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi824009049/.staging/job_local824009049_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:14,175 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi824009049/.staging/job_local824009049_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:14,220 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local824009049_0010/job_local824009049_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:14,221 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local824009049_0010/job_local824009049_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:14,221 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:14,221 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local824009049_0010
2015-02-12 15:00:14,221 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:14,222 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:14,221 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:14,224 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:14,224 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local824009049_0010_m_000000_0
2015-02-12 15:00:14,225 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:14,225 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:14,226 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt
2015-02-12 15:00:14,226 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@16ca853b
2015-02-12 15:00:14,227 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:14,250 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:14,250 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:14,250 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:14,250 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:14,250 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:14,251 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:14,251 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:14,251 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:14,259 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt"]
2015-02-12 15:00:14,259 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 15:00:14,263 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:14,263 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:14,263 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:14,263 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2015-02-12 15:00:14,263 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2015-02-12 15:00:14,266 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:14,270 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local824009049_0010_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:14,273 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/critics.txt:0+828
2015-02-12 15:00:14,273 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local824009049_0010_m_000000_0' done.
2015-02-12 15:00:14,273 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local824009049_0010_m_000000_0
2015-02-12 15:00:14,274 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:14,275 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:14,275 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local824009049_0010_r_000000_0
2015-02-12 15:00:14,277 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:14,278 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:14,278 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@61f2bf35
2015-02-12 15:00:14,279 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:14,280 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local824009049_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:14,281 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#10 about to shuffle output of map attempt_local824009049_0010_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2015-02-12 15:00:14,282 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local824009049_0010_m_000000_0
2015-02-12 15:00:14,282 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2015-02-12 15:00:14,283 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:14,286 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,286 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:14,288 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:14,289 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:14,290 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:14,291 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 1822 bytes from disk
2015-02-12 15:00:14,291 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:14,291 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:14,291 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2015-02-12 15:00:14,292 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,292 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:14,292 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:14,300 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2015-02-12 15:00:14,300 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][5739332013/euclidean/]
2015-02-12 15:00:14,321 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:14,321 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-12 15:00:14,339 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local824009049_0010_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:14,340 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,340 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local824009049_0010_r_000000_0 is allowed to commit now
2015-02-12 15:00:14,341 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local824009049_0010_r_000000_0' to file:/tmp/hadoop-soberoi/5739332013_euclidean_2852C4F57A2A489D832B4A8250BBCAE9/_temporary/0/task_local824009049_0010_r_000000
2015-02-12 15:00:14,343 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:14,343 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local824009049_0010_r_000000_0' done.
2015-02-12 15:00:14,344 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local824009049_0010_r_000000_0
2015-02-12 15:00:14,344 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:14,367 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2015-02-12 15:00:14,367 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:14,368 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:14,424 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,446 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:14,459 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:14,459 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:14,467 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local320099070_0011
2015-02-12 15:00:14,488 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi320099070/.staging/job_local320099070_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:14,489 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi320099070/.staging/job_local320099070_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:14,544 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local320099070_0011/job_local320099070_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:14,545 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local320099070_0011/job_local320099070_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:14,546 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:14,546 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:14,546 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local320099070_0011
2015-02-12 15:00:14,546 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:14,546 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:14,548 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:14,548 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local320099070_0011_m_000000_0
2015-02-12 15:00:14,550 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:14,551 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:14,553 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/5739332013_euclidean_2852C4F57A2A489D832B4A8250BBCAE9/part-00000
2015-02-12 15:00:14,553 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@37eec280
2015-02-12 15:00:14,554 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:14,580 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:14,581 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:14,581 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:14,581 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:14,581 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:14,582 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:14,582 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:14,582 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:14,587 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][5739332013/euclidean/]
2015-02-12 15:00:14,587 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 15:00:14,594 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:14,594 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:14,594 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:14,594 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2015-02-12 15:00:14,594 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2015-02-12 15:00:14,600 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:14,602 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local320099070_0011_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:14,604 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/5739332013_euclidean_2852C4F57A2A489D832B4A8250BBCAE9/part-00000:0+13816
2015-02-12 15:00:14,604 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local320099070_0011_m_000000_0' done.
2015-02-12 15:00:14,604 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local320099070_0011_m_000000_0
2015-02-12 15:00:14,604 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:14,606 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:14,606 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local320099070_0011_r_000000_0
2015-02-12 15:00:14,608 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:14,608 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:14,608 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4caba4fd
2015-02-12 15:00:14,609 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:14,609 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local320099070_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:14,611 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#11 about to shuffle output of map attempt_local320099070_0011_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2015-02-12 15:00:14,611 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local320099070_0011_m_000000_0
2015-02-12 15:00:14,611 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2015-02-12 15:00:14,611 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:14,612 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,612 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:14,614 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:14,614 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:14,617 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:14,618 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 13458 bytes from disk
2015-02-12 15:00:14,618 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:14,618 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:14,618 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2015-02-12 15:00:14,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,619 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:14,620 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:14,626 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2015-02-12 15:00:14,627 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][5230726767/euclidean/]
2015-02-12 15:00:14,652 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local320099070_0011_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:14,653 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,653 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local320099070_0011_r_000000_0 is allowed to commit now
2015-02-12 15:00:14,654 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local320099070_0011_r_000000_0' to file:/tmp/hadoop-soberoi/5230726767_euclidean_A1147384DF364FBC9F2EF9AFBEA10743/_temporary/0/task_local320099070_0011_r_000000
2015-02-12 15:00:14,655 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:14,655 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local320099070_0011_r_000000_0' done.
2015-02-12 15:00:14,655 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local320099070_0011_r_000000_0
2015-02-12 15:00:14,655 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:14,669 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...eplatform/euclidean/short
2015-02-12 15:00:14,670 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:14,671 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 15:00:14,711 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,737 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 15:00:14,750 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 15:00:14,750 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 15:00:14,755 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local989732377_0012
2015-02-12 15:00:14,772 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi989732377/.staging/job_local989732377_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:14,773 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi989732377/.staging/job_local989732377_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:14,814 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local989732377_0012/job_local989732377_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 15:00:14,815 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local989732377_0012/job_local989732377_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 15:00:14,816 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 15:00:14,816 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 15:00:14,816 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 15:00:14,818 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local989732377_0012
2015-02-12 15:00:14,818 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2015-02-12 15:00:14,820 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 15:00:14,820 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local989732377_0012_m_000000_0
2015-02-12 15:00:14,821 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:14,821 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:14,822 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-soberoi/5230726767_euclidean_A1147384DF364FBC9F2EF9AFBEA10743/part-00000
2015-02-12 15:00:14,822 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@242e7c7f
2015-02-12 15:00:14,823 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 15:00:14,846 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 15:00:14,846 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 15:00:14,846 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 15:00:14,846 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 15:00:14,846 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 15:00:14,847 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 15:00:14,847 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 15:00:14,847 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 15:00:14,853 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][5230726767/euclidean/]
2015-02-12 15:00:14,853 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 15:00:14,857 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 15:00:14,858 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 15:00:14,858 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 15:00:14,858 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 7074; bufvoid = 104857600
2015-02-12 15:00:14,858 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2015-02-12 15:00:14,860 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 15:00:14,862 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local989732377_0012_m_000000_0 is done. And is in the process of committing
2015-02-12 15:00:14,863 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-soberoi/5230726767_euclidean_A1147384DF364FBC9F2EF9AFBEA10743/part-00000:0+7726
2015-02-12 15:00:14,863 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local989732377_0012_m_000000_0' done.
2015-02-12 15:00:14,863 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local989732377_0012_m_000000_0
2015-02-12 15:00:14,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 15:00:14,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 15:00:14,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local989732377_0012_r_000000_0
2015-02-12 15:00:14,866 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 15:00:14,866 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 15:00:14,866 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@66b66b36
2015-02-12 15:00:14,866 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 15:00:14,867 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local989732377_0012_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 15:00:14,869 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#12 about to shuffle output of map attempt_local989732377_0012_m_000000_0 decomp: 7250 len: 7254 to MEMORY
2015-02-12 15:00:14,870 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 7250 bytes from map-output for attempt_local989732377_0012_m_000000_0
2015-02-12 15:00:14,870 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 7250, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->7250
2015-02-12 15:00:14,871 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 15:00:14,872 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,872 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 15:00:14,873 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:14,874 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 15:00:14,875 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 7250 bytes to disk to satisfy reduce memory limit
2015-02-12 15:00:14,876 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 7254 bytes from disk
2015-02-12 15:00:14,876 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 15:00:14,876 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 15:00:14,876 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2015-02-12 15:00:14,877 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,877 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 15:00:14,877 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 15:00:14,884 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2015-02-12 15:00:14,884 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short"]
2015-02-12 15:00:14,897 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local989732377_0012_r_000000_0 is done. And is in the process of committing
2015-02-12 15:00:14,898 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 15:00:14,898 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local989732377_0012_r_000000_0 is allowed to commit now
2015-02-12 15:00:14,899 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local989732377_0012_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short/_temporary/0/task_local989732377_0012_r_000000
2015-02-12 15:00:14,900 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 15:00:14,901 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local989732377_0012_r_000000_0' done.
2015-02-12 15:00:14,901 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local989732377_0012_r_000000_0
2015-02-12 15:00:14,901 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 15:00:14,922 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short/_temporary
2015-02-12 15:00:14,960 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,982 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 15:00:14,985 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/short