2014-04-10 10:57:53,667 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2014-04-10 10:57:53,692 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2014-04-10 10:57:53,692 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.DistanceUseCasePlatformTest
2014-04-10 10:57:53,703 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(106)) - not using cluster
2014-04-10 10:57:53,983 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2014-04-10 10:57:54,112 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2014-04-10 10:57:54,114 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(205)) - using application jar: /home/brock/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.5.3/fbde5367797af408c100d25704a77959e50a31d8/cascading-hadoop2-mr1-2.5.3.jar
2014-04-10 10:57:54,119 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: 807D5A8FC7414C789E4C6BEB02B17D3B
2014-04-10 10:57:54,165 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:54,180 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:54,233 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2014-04-10 10:57:54,261 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.5.3
2014-04-10 10:57:54,263 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] starting
2014-04-10 10:57:54,264 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:54,265 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite"]
2014-04-10 10:57:54,265 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] parallel execution is enabled: false
2014-04-10 10:57:54,267 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] starting jobs: 3
2014-04-10 10:57:54,267 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] allocating threads: 1
2014-04-10 10:57:54,268 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2014-04-10 10:57:54,287 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2014-04-10 10:57:54,288 INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2014-04-10 10:57:54,299 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:54,454 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:54,472 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:54,562 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local287230414_0001
2014-04-10 10:57:54,582 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock287230414/.staging/job_local287230414_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:54,583 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock287230414/.staging/job_local287230414_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:54,700 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local287230414_0001/job_local287230414_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:54,701 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local287230414_0001/job_local287230414_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:54,708 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:54,708 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:54,709 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local287230414_0001
2014-04-10 10:57:54,709 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:54,710 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:54,736 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:54,738 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local287230414_0001_m_000000_0
2014-04-10 10:57:54,755 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:54,759 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt
2014-04-10 10:57:54,759 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@79897ed0
2014-04-10 10:57:54,764 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:54,767 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:54,779 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:54,779 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:54,779 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:54,779 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:54,779 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:54,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:54,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:54,815 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2014-04-10 10:57:54,823 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:54,823 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2014-04-10 10:57:54,832 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:54,832 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:54,833 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:54,833 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2014-04-10 10:57:54,833 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2014-04-10 10:57:54,840 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:54,842 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local287230414_0001_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:54,847 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt:0+828
2014-04-10 10:57:54,847 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local287230414_0001_m_000000_0' done.
2014-04-10 10:57:54,847 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local287230414_0001_m_000000_0
2014-04-10 10:57:54,848 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:54,849 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:54,849 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local287230414_0001_r_000000_0
2014-04-10 10:57:54,853 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:54,855 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4cbde97a
2014-04-10 10:57:54,861 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:54,863 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local287230414_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:54,879 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#1 about to shuffle output of map attempt_local287230414_0001_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2014-04-10 10:57:54,881 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local287230414_0001_m_000000_0
2014-04-10 10:57:54,896 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2014-04-10 10:57:54,897 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:54,898 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:54,898 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:54,907 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:54,907 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:54,910 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:54,910 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 1822 bytes from disk
2014-04-10 10:57:54,911 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:54,911 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:54,911 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:54,912 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:54,913 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:54,913 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:54,925 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2014-04-10 10:57:54,925 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][4929331539/euclidean/]
2014-04-10 10:57:54,942 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:54,942 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:54,971 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local287230414_0001_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:54,972 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:54,972 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local287230414_0001_r_000000_0 is allowed to commit now
2014-04-10 10:57:54,973 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local287230414_0001_r_000000_0' to file:/tmp/hadoop-brock/4929331539_euclidean_CFDA5D44BFBB42DAA1C5B8FF8BD9F1A3/_temporary/0/task_local287230414_0001_r_000000
2014-04-10 10:57:54,973 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:54,974 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local287230414_0001_r_000000_0' done.
2014-04-10 10:57:54,974 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local287230414_0001_r_000000_0
2014-04-10 10:57:54,974 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:54,995 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2014-04-10 10:57:54,995 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:54,997 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,026 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,041 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:55,051 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:55,052 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:55,065 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1100089751_0002
2014-04-10 10:57:55,075 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock1100089751/.staging/job_local1100089751_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,075 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock1100089751/.staging/job_local1100089751_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,117 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local1100089751_0002/job_local1100089751_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,117 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local1100089751_0002/job_local1100089751_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,118 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:55,118 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:55,118 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local1100089751_0002
2014-04-10 10:57:55,119 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:55,119 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:55,120 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:55,120 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1100089751_0002_m_000000_0
2014-04-10 10:57:55,122 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,122 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/4929331539_euclidean_CFDA5D44BFBB42DAA1C5B8FF8BD9F1A3/part-00000
2014-04-10 10:57:55,123 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@50d42ff4
2014-04-10 10:57:55,128 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:55,128 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:55,139 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:55,139 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:55,139 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:55,139 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:55,139 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:55,140 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:55,140 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,147 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][4929331539/euclidean/]
2014-04-10 10:57:55,147 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2014-04-10 10:57:55,165 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:55,165 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:55,165 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:55,165 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2014-04-10 10:57:55,165 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2014-04-10 10:57:55,197 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:55,199 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1100089751_0002_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,200 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/4929331539_euclidean_CFDA5D44BFBB42DAA1C5B8FF8BD9F1A3/part-00000:0+13816
2014-04-10 10:57:55,201 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1100089751_0002_m_000000_0' done.
2014-04-10 10:57:55,201 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1100089751_0002_m_000000_0
2014-04-10 10:57:55,201 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:55,201 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:55,201 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1100089751_0002_r_000000_0
2014-04-10 10:57:55,203 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,203 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@69909fd4
2014-04-10 10:57:55,203 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:55,204 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1100089751_0002_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:55,205 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#2 about to shuffle output of map attempt_local1100089751_0002_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2014-04-10 10:57:55,205 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local1100089751_0002_m_000000_0
2014-04-10 10:57:55,205 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2014-04-10 10:57:55,205 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:55,206 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,206 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:55,207 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,207 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:55,211 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:55,211 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 13458 bytes from disk
2014-04-10 10:57:55,211 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:55,211 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,212 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:55,212 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,212 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:55,212 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,222 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2014-04-10 10:57:55,222 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][9100640069/euclidean/]
2014-04-10 10:57:55,241 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1100089751_0002_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,242 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,242 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1100089751_0002_r_000000_0 is allowed to commit now
2014-04-10 10:57:55,242 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1100089751_0002_r_000000_0' to file:/tmp/hadoop-brock/9100640069_euclidean_5226B24434BF4672A85EF7C8CAFE3219/_temporary/0/task_local1100089751_0002_r_000000
2014-04-10 10:57:55,243 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:55,243 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1100089751_0002_r_000000_0' done.
2014-04-10 10:57:55,243 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1100089751_0002_r_000000_0
2014-04-10 10:57:55,244 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:55,258 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...tform/euclidean/composite
2014-04-10 10:57:55,258 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,259 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,272 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,278 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:55,283 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:55,284 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:55,297 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local776964600_0003
2014-04-10 10:57:55,309 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock776964600/.staging/job_local776964600_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,309 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock776964600/.staging/job_local776964600_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,341 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local776964600_0003/job_local776964600_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,342 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local776964600_0003/job_local776964600_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,342 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:55,343 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:55,343 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local776964600_0003
2014-04-10 10:57:55,343 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:55,343 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:55,345 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:55,345 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local776964600_0003_m_000000_0
2014-04-10 10:57:55,346 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,347 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/9100640069_euclidean_5226B24434BF4672A85EF7C8CAFE3219/part-00000
2014-04-10 10:57:55,347 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4e7c484c
2014-04-10 10:57:55,349 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:55,349 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:55,359 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:55,359 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:55,360 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:55,360 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:55,360 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:55,360 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:55,360 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,367 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][9100640069/euclidean/]
2014-04-10 10:57:55,367 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2014-04-10 10:57:55,373 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:55,373 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:55,373 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:55,373 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 6291; bufvoid = 104857600
2014-04-10 10:57:55,373 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2014-04-10 10:57:55,378 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:55,379 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local776964600_0003_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,380 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/9100640069_euclidean_5226B24434BF4672A85EF7C8CAFE3219/part-00000:0+6943
2014-04-10 10:57:55,380 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local776964600_0003_m_000000_0' done.
2014-04-10 10:57:55,380 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local776964600_0003_m_000000_0
2014-04-10 10:57:55,381 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:55,381 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:55,381 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local776964600_0003_r_000000_0
2014-04-10 10:57:55,382 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,382 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4e57790a
2014-04-10 10:57:55,383 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:55,383 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local776964600_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:55,384 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#3 about to shuffle output of map attempt_local776964600_0003_m_000000_0 decomp: 6467 len: 6471 to MEMORY
2014-04-10 10:57:55,384 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 6467 bytes from map-output for attempt_local776964600_0003_m_000000_0
2014-04-10 10:57:55,385 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 6467, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->6467
2014-04-10 10:57:55,385 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:55,385 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,385 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:55,387 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,387 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2014-04-10 10:57:55,389 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 6467 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:55,389 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 6471 bytes from disk
2014-04-10 10:57:55,389 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:55,389 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,389 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2014-04-10 10:57:55,390 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,390 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:55,390 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,397 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2014-04-10 10:57:55,397 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite"]
2014-04-10 10:57:55,408 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local776964600_0003_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,409 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,410 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local776964600_0003_r_000000_0 is allowed to commit now
2014-04-10 10:57:55,410 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local776964600_0003_r_000000_0' to file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite/_temporary/0/task_local776964600_0003_r_000000
2014-04-10 10:57:55,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:55,411 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local776964600_0003_r_000000_0' done.
2014-04-10 10:57:55,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local776964600_0003_r_000000_0
2014-04-10 10:57:55,412 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:55,440 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/composite/_temporary
2014-04-10 10:57:55,458 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,477 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,479 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/composite
2014-04-10 10:57:55,496 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2014-04-10 10:57:55,497 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(205)) - using application jar: /home/brock/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.5.3/fbde5367797af408c100d25704a77959e50a31d8/cascading-hadoop2-mr1-2.5.3.jar
2014-04-10 10:57:55,512 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:55,515 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:55,530 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2014-04-10 10:57:55,536 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [pearson] starting
2014-04-10 10:57:55,536 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [pearson] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:55,537 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [pearson] sink: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite"]
2014-04-10 10:57:55,537 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [pearson] parallel execution is enabled: false
2014-04-10 10:57:55,537 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [pearson] starting jobs: 3
2014-04-10 10:57:55,537 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [pearson] allocating threads: 1
2014-04-10 10:57:55,538 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (1/3)
2014-04-10 10:57:55,538 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,539 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,552 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,565 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:55,580 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1984372893_0004
2014-04-10 10:57:55,595 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock1984372893/.staging/job_local1984372893_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,595 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock1984372893/.staging/job_local1984372893_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,627 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local1984372893_0004/job_local1984372893_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,627 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local1984372893_0004/job_local1984372893_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,628 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:55,628 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local1984372893_0004
2014-04-10 10:57:55,628 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:55,628 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2014-04-10 10:57:55,629 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:55,631 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:55,631 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1984372893_0004_m_000000_0
2014-04-10 10:57:55,634 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,635 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt
2014-04-10 10:57:55,635 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@48e266df
2014-04-10 10:57:55,637 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:55,638 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:55,648 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:55,648 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:55,648 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:55,648 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:55,648 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:55,649 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:55,649 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,657 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:55,657 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2014-04-10 10:57:55,660 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:55,660 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:55,660 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:55,661 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2014-04-10 10:57:55,661 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2014-04-10 10:57:55,663 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:55,664 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1984372893_0004_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,665 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt:0+828
2014-04-10 10:57:55,665 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1984372893_0004_m_000000_0' done.
2014-04-10 10:57:55,665 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1984372893_0004_m_000000_0
2014-04-10 10:57:55,665 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:55,666 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:55,666 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1984372893_0004_r_000000_0
2014-04-10 10:57:55,667 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,667 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@566809da
2014-04-10 10:57:55,667 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:55,668 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1984372893_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:55,669 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#4 about to shuffle output of map attempt_local1984372893_0004_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2014-04-10 10:57:55,670 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local1984372893_0004_m_000000_0
2014-04-10 10:57:55,670 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2014-04-10 10:57:55,670 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:55,671 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,671 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:55,672 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,672 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:55,673 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:55,673 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 1822 bytes from disk
2014-04-10 10:57:55,673 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:55,673 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,674 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:55,674 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,674 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:55,674 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,683 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2014-04-10 10:57:55,683 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][421323841/pearson/]
2014-04-10 10:57:55,688 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:55,688 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:55,704 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1984372893_0004_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,705 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,705 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1984372893_0004_r_000000_0 is allowed to commit now
2014-04-10 10:57:55,706 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1984372893_0004_r_000000_0' to file:/tmp/hadoop-brock/421323841_pearson_D11A00A115FB4FF4B194ABEE5AA8120F/_temporary/0/task_local1984372893_0004_r_000000
2014-04-10 10:57:55,706 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:55,706 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1984372893_0004_r_000000_0' done.
2014-04-10 10:57:55,706 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1984372893_0004_r_000000_0
2014-04-10 10:57:55,707 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:55,729 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (2/3)
2014-04-10 10:57:55,729 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,731 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,754 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,767 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:55,775 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:55,775 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:55,787 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local72197038_0005
2014-04-10 10:57:55,796 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock72197038/.staging/job_local72197038_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,796 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock72197038/.staging/job_local72197038_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,826 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local72197038_0005/job_local72197038_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,826 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local72197038_0005/job_local72197038_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:55,827 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:55,827 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:55,827 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local72197038_0005
2014-04-10 10:57:55,828 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2014-04-10 10:57:55,827 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:55,830 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:55,830 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local72197038_0005_m_000000_0
2014-04-10 10:57:55,833 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,834 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/421323841_pearson_D11A00A115FB4FF4B194ABEE5AA8120F/part-00000
2014-04-10 10:57:55,835 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1a1fc11
2014-04-10 10:57:55,836 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:55,837 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:55,852 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:55,853 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:55,853 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:55,853 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:55,853 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:55,854 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:55,854 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,859 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][421323841/pearson/]
2014-04-10 10:57:55,859 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2014-04-10 10:57:55,867 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:55,867 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:55,867 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:55,867 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2014-04-10 10:57:55,868 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2014-04-10 10:57:55,876 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:55,878 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local72197038_0005_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,879 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/421323841_pearson_D11A00A115FB4FF4B194ABEE5AA8120F/part-00000:0+13816
2014-04-10 10:57:55,879 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local72197038_0005_m_000000_0' done.
2014-04-10 10:57:55,879 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local72197038_0005_m_000000_0
2014-04-10 10:57:55,879 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:55,880 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:55,880 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local72197038_0005_r_000000_0
2014-04-10 10:57:55,881 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:55,881 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1edd855d
2014-04-10 10:57:55,881 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:55,882 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local72197038_0005_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:55,883 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#5 about to shuffle output of map attempt_local72197038_0005_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2014-04-10 10:57:55,883 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local72197038_0005_m_000000_0
2014-04-10 10:57:55,883 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2014-04-10 10:57:55,883 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:55,884 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,884 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:55,885 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,885 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:55,887 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:55,887 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 13458 bytes from disk
2014-04-10 10:57:55,887 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:55,887 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:55,888 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:55,888 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,888 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:55,888 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:55,893 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2014-04-10 10:57:55,893 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][7858931233/pearson/]
2014-04-10 10:57:55,909 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local72197038_0005_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:55,910 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:55,910 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local72197038_0005_r_000000_0 is allowed to commit now
2014-04-10 10:57:55,910 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local72197038_0005_r_000000_0' to file:/tmp/hadoop-brock/7858931233_pearson_69AC75C3BC51422BB9C1711E942C17BF/_temporary/0/task_local72197038_0005_r_000000
2014-04-10 10:57:55,911 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:55,911 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local72197038_0005_r_000000_0' done.
2014-04-10 10:57:55,911 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local72197038_0005_r_000000_0
2014-04-10 10:57:55,911 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:55,928 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] starting step: (3/3) ...latform/pearson/composite
2014-04-10 10:57:55,929 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,930 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:55,948 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:55,960 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:55,968 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:55,968 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:55,974 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1033148360_0006
2014-04-10 10:57:55,984 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock1033148360/.staging/job_local1033148360_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:55,985 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock1033148360/.staging/job_local1033148360_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,018 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local1033148360_0006/job_local1033148360_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,018 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local1033148360_0006/job_local1033148360_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,019 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:56,019 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] submitted hadoop job: job_local1033148360_0006
2014-04-10 10:57:56,019 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:56,019 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:56,019 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pearson] tracking url: http://localhost:8080/
2014-04-10 10:57:56,022 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:56,022 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1033148360_0006_m_000000_0
2014-04-10 10:57:56,024 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,025 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/7858931233_pearson_69AC75C3BC51422BB9C1711E942C17BF/part-00000
2014-04-10 10:57:56,026 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@513e5f5a
2014-04-10 10:57:56,027 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:56,027 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:56,083 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:56,083 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:56,083 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:56,083 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:56,083 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:56,084 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:56,084 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,089 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][7858931233/pearson/]
2014-04-10 10:57:56,089 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2014-04-10 10:57:56,093 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:56,093 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:56,093 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:56,093 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 6291; bufvoid = 104857600
2014-04-10 10:57:56,094 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2014-04-10 10:57:56,096 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:56,097 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1033148360_0006_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,098 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/7858931233_pearson_69AC75C3BC51422BB9C1711E942C17BF/part-00000:0+6943
2014-04-10 10:57:56,099 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1033148360_0006_m_000000_0' done.
2014-04-10 10:57:56,099 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1033148360_0006_m_000000_0
2014-04-10 10:57:56,099 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:56,099 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:56,099 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1033148360_0006_r_000000_0
2014-04-10 10:57:56,100 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,100 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@31ec6bb1
2014-04-10 10:57:56,101 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:56,101 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1033148360_0006_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:56,103 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#6 about to shuffle output of map attempt_local1033148360_0006_m_000000_0 decomp: 6467 len: 6471 to MEMORY
2014-04-10 10:57:56,103 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 6467 bytes from map-output for attempt_local1033148360_0006_m_000000_0
2014-04-10 10:57:56,103 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 6467, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->6467
2014-04-10 10:57:56,104 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:56,104 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,104 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:56,105 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,105 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2014-04-10 10:57:56,107 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 6467 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:56,107 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 6471 bytes from disk
2014-04-10 10:57:56,107 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:56,107 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,107 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 6432 bytes
2014-04-10 10:57:56,108 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,108 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:56,108 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,114 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2014-04-10 10:57:56,114 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite"]
2014-04-10 10:57:56,131 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1033148360_0006_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,132 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,132 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1033148360_0006_r_000000_0 is allowed to commit now
2014-04-10 10:57:56,133 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1033148360_0006_r_000000_0' to file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite/_temporary/0/task_local1033148360_0006_r_000000
2014-04-10 10:57:56,134 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:56,134 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1033148360_0006_r_000000_0' done.
2014-04-10 10:57:56,134 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1033148360_0006_r_000000_0
2014-04-10 10:57:56,134 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:56,152 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/pearson/composite/_temporary
2014-04-10 10:57:56,177 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,199 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,200 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output//hadoop2-mr1/distanceusecaseplatform/pearson/composite
2014-04-10 10:57:56,214 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2014-04-10 10:57:56,214 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(205)) - using application jar: /home/brock/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.5.3/fbde5367797af408c100d25704a77959e50a31d8/cascading-hadoop2-mr1-2.5.3.jar
2014-04-10 10:57:56,261 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:56,265 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:56,278 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2014-04-10 10:57:56,286 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] starting
2014-04-10 10:57:56,286 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:56,287 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long"]
2014-04-10 10:57:56,287 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] parallel execution is enabled: false
2014-04-10 10:57:56,287 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] starting jobs: 3
2014-04-10 10:57:56,287 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] allocating threads: 1
2014-04-10 10:57:56,287 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2014-04-10 10:57:56,288 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,289 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,308 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,320 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:56,334 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local416326803_0007
2014-04-10 10:57:56,346 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock416326803/.staging/job_local416326803_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,347 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock416326803/.staging/job_local416326803_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,376 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local416326803_0007/job_local416326803_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,376 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local416326803_0007/job_local416326803_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,377 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:56,377 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local416326803_0007
2014-04-10 10:57:56,377 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:56,377 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:56,378 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:56,380 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:56,380 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local416326803_0007_m_000000_0
2014-04-10 10:57:56,382 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,384 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt
2014-04-10 10:57:56,384 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@59e07b40
2014-04-10 10:57:56,385 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:56,386 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:56,400 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:56,400 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:56,400 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:56,400 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:56,400 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:56,401 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:56,401 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,406 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:56,406 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2014-04-10 10:57:56,408 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:56,409 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:56,409 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:56,409 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2014-04-10 10:57:56,409 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2014-04-10 10:57:56,411 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:56,412 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local416326803_0007_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,413 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt:0+828
2014-04-10 10:57:56,413 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local416326803_0007_m_000000_0' done.
2014-04-10 10:57:56,413 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local416326803_0007_m_000000_0
2014-04-10 10:57:56,413 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:56,413 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:56,414 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local416326803_0007_r_000000_0
2014-04-10 10:57:56,415 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,415 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@27e1d8a2
2014-04-10 10:57:56,415 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:56,416 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local416326803_0007_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:56,417 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#7 about to shuffle output of map attempt_local416326803_0007_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2014-04-10 10:57:56,418 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local416326803_0007_m_000000_0
2014-04-10 10:57:56,418 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2014-04-10 10:57:56,418 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:56,419 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,419 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:56,420 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,420 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:56,422 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:56,422 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 1822 bytes from disk
2014-04-10 10:57:56,422 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:56,422 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,422 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:56,423 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,423 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:56,423 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,429 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2014-04-10 10:57:56,429 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][8803725501/euclidean/]
2014-04-10 10:57:56,433 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:56,433 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:56,449 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local416326803_0007_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,450 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,450 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local416326803_0007_r_000000_0 is allowed to commit now
2014-04-10 10:57:56,451 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local416326803_0007_r_000000_0' to file:/tmp/hadoop-brock/8803725501_euclidean_B189991CA3DF494B80322D842AC4849B/_temporary/0/task_local416326803_0007_r_000000
2014-04-10 10:57:56,451 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:56,452 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local416326803_0007_r_000000_0' done.
2014-04-10 10:57:56,452 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local416326803_0007_r_000000_0
2014-04-10 10:57:56,452 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:56,467 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2014-04-10 10:57:56,468 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,468 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,488 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,497 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:56,504 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:56,505 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:56,510 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local2101357167_0008
2014-04-10 10:57:56,523 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock2101357167/.staging/job_local2101357167_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,524 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock2101357167/.staging/job_local2101357167_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,548 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local2101357167_0008/job_local2101357167_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,548 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local2101357167_0008/job_local2101357167_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,549 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:56,549 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local2101357167_0008
2014-04-10 10:57:56,549 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:56,549 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:56,549 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:56,552 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:56,552 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local2101357167_0008_m_000000_0
2014-04-10 10:57:56,554 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,556 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/8803725501_euclidean_B189991CA3DF494B80322D842AC4849B/part-00000
2014-04-10 10:57:56,556 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1e58c9aa
2014-04-10 10:57:56,558 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:56,558 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:56,572 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:56,572 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:56,572 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:56,572 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:56,572 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:56,573 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:56,573 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,577 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][8803725501/euclidean/]
2014-04-10 10:57:56,578 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2014-04-10 10:57:56,583 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:56,583 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:56,583 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:56,583 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2014-04-10 10:57:56,583 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2014-04-10 10:57:56,590 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:56,591 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local2101357167_0008_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,592 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/8803725501_euclidean_B189991CA3DF494B80322D842AC4849B/part-00000:0+13816
2014-04-10 10:57:56,592 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local2101357167_0008_m_000000_0' done.
2014-04-10 10:57:56,592 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local2101357167_0008_m_000000_0
2014-04-10 10:57:56,592 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:56,592 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:56,592 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local2101357167_0008_r_000000_0
2014-04-10 10:57:56,594 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,594 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7f94ee59
2014-04-10 10:57:56,594 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:56,595 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local2101357167_0008_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:56,596 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#8 about to shuffle output of map attempt_local2101357167_0008_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2014-04-10 10:57:56,596 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local2101357167_0008_m_000000_0
2014-04-10 10:57:56,596 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2014-04-10 10:57:56,596 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:56,597 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,597 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:56,599 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,599 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:56,601 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:56,601 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 13458 bytes from disk
2014-04-10 10:57:56,601 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:56,601 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,601 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:56,602 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,602 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:56,602 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,606 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2014-04-10 10:57:56,606 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][9771932617/euclidean/]
2014-04-10 10:57:56,620 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local2101357167_0008_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,621 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,621 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local2101357167_0008_r_000000_0 is allowed to commit now
2014-04-10 10:57:56,621 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local2101357167_0008_r_000000_0' to file:/tmp/hadoop-brock/9771932617_euclidean_1FAD4DFB622148369E2AA146215CED57/_temporary/0/task_local2101357167_0008_r_000000
2014-04-10 10:57:56,622 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:56,622 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local2101357167_0008_r_000000_0' done.
2014-04-10 10:57:56,622 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local2101357167_0008_r_000000_0
2014-04-10 10:57:56,622 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:56,635 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...seplatform/euclidean/long
2014-04-10 10:57:56,635 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,636 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,657 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,669 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:56,676 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:56,676 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:56,679 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local64137267_0009
2014-04-10 10:57:56,691 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock64137267/.staging/job_local64137267_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,691 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock64137267/.staging/job_local64137267_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,714 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local64137267_0009/job_local64137267_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,714 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local64137267_0009/job_local64137267_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,714 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:56,715 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local64137267_0009
2014-04-10 10:57:56,715 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:56,715 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:56,715 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:56,718 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:56,718 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local64137267_0009_m_000000_0
2014-04-10 10:57:56,720 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,721 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/9771932617_euclidean_1FAD4DFB622148369E2AA146215CED57/part-00000
2014-04-10 10:57:56,721 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6b075908
2014-04-10 10:57:56,723 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:56,723 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:56,735 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:56,735 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:56,735 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:56,735 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:56,735 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:56,736 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:56,736 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,740 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][9771932617/euclidean/]
2014-04-10 10:57:56,740 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2014-04-10 10:57:56,744 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:56,744 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:56,744 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:56,744 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 7074; bufvoid = 104857600
2014-04-10 10:57:56,744 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2014-04-10 10:57:56,747 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:56,748 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local64137267_0009_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,750 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/9771932617_euclidean_1FAD4DFB622148369E2AA146215CED57/part-00000:0+7726
2014-04-10 10:57:56,750 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local64137267_0009_m_000000_0' done.
2014-04-10 10:57:56,750 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local64137267_0009_m_000000_0
2014-04-10 10:57:56,750 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:56,750 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:56,750 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local64137267_0009_r_000000_0
2014-04-10 10:57:56,752 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,753 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@d1f28f4
2014-04-10 10:57:56,754 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:56,754 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local64137267_0009_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:56,755 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#9 about to shuffle output of map attempt_local64137267_0009_m_000000_0 decomp: 7250 len: 7254 to MEMORY
2014-04-10 10:57:56,756 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 7250 bytes from map-output for attempt_local64137267_0009_m_000000_0
2014-04-10 10:57:56,756 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 7250, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->7250
2014-04-10 10:57:56,757 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:56,757 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,758 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:56,760 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,760 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2014-04-10 10:57:56,762 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 7250 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:56,762 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 7254 bytes from disk
2014-04-10 10:57:56,763 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:56,763 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,763 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2014-04-10 10:57:56,764 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:56,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,771 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2014-04-10 10:57:56,771 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long"]
2014-04-10 10:57:56,781 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local64137267_0009_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,782 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,782 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local64137267_0009_r_000000_0 is allowed to commit now
2014-04-10 10:57:56,783 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local64137267_0009_r_000000_0' to file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long/_temporary/0/task_local64137267_0009_r_000000
2014-04-10 10:57:56,784 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:56,784 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local64137267_0009_r_000000_0' done.
2014-04-10 10:57:56,784 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local64137267_0009_r_000000_0
2014-04-10 10:57:56,784 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:56,801 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/long/_temporary
2014-04-10 10:57:56,825 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,841 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,842 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/long
2014-04-10 10:57:56,858 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2014-04-10 10:57:56,858 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(205)) - using application jar: /home/brock/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.5.3/fbde5367797af408c100d25704a77959e50a31d8/cascading-hadoop2-mr1-2.5.3.jar
2014-04-10 10:57:56,869 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:56,870 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:56,880 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2014-04-10 10:57:56,886 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] starting
2014-04-10 10:57:56,886 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:56,886 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short"]
2014-04-10 10:57:56,887 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] parallel execution is enabled: false
2014-04-10 10:57:56,887 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] starting jobs: 3
2014-04-10 10:57:56,887 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [euclidean] allocating threads: 1
2014-04-10 10:57:56,887 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (1/3)
2014-04-10 10:57:56,888 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,889 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:56,904 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:56,916 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:56,928 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local138424054_0010
2014-04-10 10:57:56,936 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock138424054/.staging/job_local138424054_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,936 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock138424054/.staging/job_local138424054_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,960 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local138424054_0010/job_local138424054_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:56,960 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local138424054_0010/job_local138424054_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:56,960 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:56,961 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local138424054_0010
2014-04-10 10:57:56,961 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:56,961 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:56,961 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:56,962 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:56,962 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local138424054_0010_m_000000_0
2014-04-10 10:57:56,963 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,964 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt
2014-04-10 10:57:56,964 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3007d251
2014-04-10 10:57:56,965 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:56,965 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:56,976 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:56,976 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:56,976 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:56,976 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:56,977 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:56,977 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:56,977 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,981 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt"]
2014-04-10 10:57:56,981 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2014-04-10 10:57:56,984 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:56,984 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:56,984 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:56,984 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 1746; bufvoid = 104857600
2014-04-10 10:57:56,984 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214260(104857040); length = 137/6553600
2014-04-10 10:57:56,986 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:56,987 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local138424054_0010_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:56,988 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/classes/test/data/critics.txt:0+828
2014-04-10 10:57:56,988 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local138424054_0010_m_000000_0' done.
2014-04-10 10:57:56,988 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local138424054_0010_m_000000_0
2014-04-10 10:57:56,988 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:56,988 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:56,988 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local138424054_0010_r_000000_0
2014-04-10 10:57:56,989 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:56,989 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@15b78021
2014-04-10 10:57:56,990 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:56,990 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local138424054_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:56,991 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#10 about to shuffle output of map attempt_local138424054_0010_m_000000_0 decomp: 1818 len: 1822 to MEMORY
2014-04-10 10:57:56,991 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 1818 bytes from map-output for attempt_local138424054_0010_m_000000_0
2014-04-10 10:57:56,991 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 1818, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->1818
2014-04-10 10:57:56,991 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:56,992 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,992 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:56,993 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,993 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:56,994 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 1818 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:56,994 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 1822 bytes from disk
2014-04-10 10:57:56,994 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:56,994 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:56,994 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 1797 bytes
2014-04-10 10:57:56,995 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:56,995 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:56,995 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:56,999 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2014-04-10 10:57:56,999 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][6120007256/euclidean/]
2014-04-10 10:57:57,002 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:57,002 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2014-04-10 10:57:57,014 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local138424054_0010_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:57,015 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,016 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local138424054_0010_r_000000_0 is allowed to commit now
2014-04-10 10:57:57,016 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local138424054_0010_r_000000_0' to file:/tmp/hadoop-brock/6120007256_euclidean_497161F311C241FDB76E01AB09923913/_temporary/0/task_local138424054_0010_r_000000
2014-04-10 10:57:57,017 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:57,017 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local138424054_0010_r_000000_0' done.
2014-04-10 10:57:57,017 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local138424054_0010_r_000000_0
2014-04-10 10:57:57,017 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:57,039 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (2/3)
2014-04-10 10:57:57,040 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:57,040 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:57,060 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:57,072 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:57,078 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:57,078 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:57,081 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local522815801_0011
2014-04-10 10:57:57,090 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock522815801/.staging/job_local522815801_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:57,090 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock522815801/.staging/job_local522815801_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:57,111 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local522815801_0011/job_local522815801_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:57,112 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local522815801_0011/job_local522815801_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:57,112 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:57,112 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:57,112 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local522815801_0011
2014-04-10 10:57:57,113 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:57,113 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:57,115 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:57,115 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local522815801_0011_m_000000_0
2014-04-10 10:57:57,117 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:57,118 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/6120007256_euclidean_497161F311C241FDB76E01AB09923913/part-00000
2014-04-10 10:57:57,118 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4c185bfb
2014-04-10 10:57:57,120 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:57,120 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:57,133 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:57,133 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:57,133 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:57,133 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:57,133 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:57,134 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:57,134 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:57,138 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][6120007256/euclidean/]
2014-04-10 10:57:57,138 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2014-04-10 10:57:57,144 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:57,144 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:57,144 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:57,144 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 13104; bufvoid = 104857600
2014-04-10 10:57:57,144 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26213704(104854816); length = 693/6553600
2014-04-10 10:57:57,148 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:57,149 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local522815801_0011_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:57,150 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/6120007256_euclidean_497161F311C241FDB76E01AB09923913/part-00000:0+13816
2014-04-10 10:57:57,150 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local522815801_0011_m_000000_0' done.
2014-04-10 10:57:57,150 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local522815801_0011_m_000000_0
2014-04-10 10:57:57,150 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:57,150 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:57,151 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local522815801_0011_r_000000_0
2014-04-10 10:57:57,153 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:57,153 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@712a02e
2014-04-10 10:57:57,154 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=495085152, maxSingleShuffleLimit=123771288, mergeThreshold=326756224, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:57,154 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local522815801_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:57,156 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#11 about to shuffle output of map attempt_local522815801_0011_m_000000_0 decomp: 13454 len: 13458 to MEMORY
2014-04-10 10:57:57,156 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 13454 bytes from map-output for attempt_local522815801_0011_m_000000_0
2014-04-10 10:57:57,156 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 13454, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->13454
2014-04-10 10:57:57,157 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:57,158 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,158 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:57,159 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:57,159 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:57,160 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 13454 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:57,160 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 13458 bytes from disk
2014-04-10 10:57:57,160 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:57,161 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:57,161 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 13386 bytes
2014-04-10 10:57:57,161 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,161 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:57,161 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:57,165 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2014-04-10 10:57:57,165 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][6906649664/euclidean/]
2014-04-10 10:57:57,182 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local522815801_0011_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:57,183 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,183 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local522815801_0011_r_000000_0 is allowed to commit now
2014-04-10 10:57:57,183 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local522815801_0011_r_000000_0' to file:/tmp/hadoop-brock/6906649664_euclidean_99D50121F19B43F7BAC81C5B359AE8C9/_temporary/0/task_local522815801_0011_r_000000
2014-04-10 10:57:57,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:57,184 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local522815801_0011_r_000000_0' done.
2014-04-10 10:57:57,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local522815801_0011_r_000000_0
2014-04-10 10:57:57,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:57,200 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] starting step: (3/3) ...eplatform/euclidean/short
2014-04-10 10:57:57,200 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:57,201 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-04-10 10:57:57,221 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:57,232 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-04-10 10:57:57,239 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-04-10 10:57:57,239 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-04-10 10:57:57,244 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local116893347_0012
2014-04-10 10:57:57,254 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock116893347/.staging/job_local116893347_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:57,254 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/staging/brock116893347/.staging/job_local116893347_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:57,288 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local116893347_0012/job_local116893347_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-04-10 10:57:57,288 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/tmp/mapred/local/localRunner/brock/job_local116893347_0012/job_local116893347_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-04-10 10:57:57,289 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-04-10 10:57:57,289 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] submitted hadoop job: job_local116893347_0012
2014-04-10 10:57:57,289 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-04-10 10:57:57,289 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [euclidean] tracking url: http://localhost:8080/
2014-04-10 10:57:57,290 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-04-10 10:57:57,292 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-04-10 10:57:57,292 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local116893347_0012_m_000000_0
2014-04-10 10:57:57,294 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:57,295 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-brock/6906649664_euclidean_99D50121F19B43F7BAC81C5B359AE8C9/part-00000
2014-04-10 10:57:57,295 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6ff28e4d
2014-04-10 10:57:57,297 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-04-10 10:57:57,297 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-04-10 10:57:57,311 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-04-10 10:57:57,311 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-04-10 10:57:57,311 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-04-10 10:57:57,311 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-04-10 10:57:57,311 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-04-10 10:57:57,312 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.5.3
2014-04-10 10:57:57,312 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2014-04-10 10:57:57,316 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][6906649664/euclidean/]
2014-04-10 10:57:57,316 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2014-04-10 10:57:57,319 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-04-10 10:57:57,319 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-04-10 10:57:57,319 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-04-10 10:57:57,319 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 7074; bufvoid = 104857600
2014-04-10 10:57:57,319 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214052(104856208); length = 345/6553600
2014-04-10 10:57:57,321 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-04-10 10:57:57,322 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local116893347_0012_m_000000_0 is done. And is in the process of committing
2014-04-10 10:57:57,323 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-brock/6906649664_euclidean_99D50121F19B43F7BAC81C5B359AE8C9/part-00000:0+7726
2014-04-10 10:57:57,323 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local116893347_0012_m_000000_0' done.
2014-04-10 10:57:57,323 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local116893347_0012_m_000000_0
2014-04-10 10:57:57,323 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-04-10 10:57:57,324 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-04-10 10:57:57,324 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local116893347_0012_r_000000_0
2014-04-10 10:57:57,326 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-04-10 10:57:57,326 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@6d618ddd
2014-04-10 10:57:57,327 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=496966048, maxSingleShuffleLimit=124241512, mergeThreshold=327997600, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-04-10 10:57:57,327 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local116893347_0012_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-04-10 10:57:57,329 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#12 about to shuffle output of map attempt_local116893347_0012_m_000000_0 decomp: 7250 len: 7254 to MEMORY
2014-04-10 10:57:57,329 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 7250 bytes from map-output for attempt_local116893347_0012_m_000000_0
2014-04-10 10:57:57,329 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 7250, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->7250
2014-04-10 10:57:57,329 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-04-10 10:57:57,330 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,330 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-04-10 10:57:57,331 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:57,331 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2014-04-10 10:57:57,332 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 7250 bytes to disk to satisfy reduce memory limit
2014-04-10 10:57:57,333 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 7254 bytes from disk
2014-04-10 10:57:57,333 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-04-10 10:57:57,333 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-04-10 10:57:57,333 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 7215 bytes
2014-04-10 10:57:57,334 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,334 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.5.3
2014-04-10 10:57:57,334 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2014-04-10 10:57:57,340 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2014-04-10 10:57:57,341 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short"]
2014-04-10 10:57:57,351 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local116893347_0012_r_000000_0 is done. And is in the process of committing
2014-04-10 10:57:57,351 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-04-10 10:57:57,351 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local116893347_0012_r_000000_0 is allowed to commit now
2014-04-10 10:57:57,352 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local116893347_0012_r_000000_0' to file:/home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short/_temporary/0/task_local116893347_0012_r_000000
2014-04-10 10:57:57,353 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-04-10 10:57:57,353 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local116893347_0012_r_000000_0' done.
2014-04-10 10:57:57,353 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local116893347_0012_r_000000_0
2014-04-10 10:57:57,354 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-04-10 10:57:57,371 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output/hadoop2-mr1/distanceusecaseplatform/euclidean/short/_temporary
2014-04-10 10:57:57,392 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:57,407 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-04-10 10:57:57,409 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /home/brock/workspaces/cascading-compat/cascading.compatibility/cloudera-hadoop2-5.0/build/test/output//hadoop2-mr1/distanceusecaseplatform/euclidean/short