2013-10-23 22:51:48,197 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2013-10-23 22:51:48,211 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2013-10-23 22:51:48,212 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.DistanceUseCasePlatformTest
2013-10-23 22:51:48,226 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2013-10-23 22:51:48,504 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-10-23 22:51:48,505 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /Users/jwfbean/.gradle/caches/artifacts-26/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-10-23 22:51:48,513 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: B905BA0BE0244132B2BDC6E0477F24A2
2013-10-23 22:51:48,669 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.2.0
2013-10-23 22:51:48,670 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] starting
2013-10-23 22:51:48,671 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:48,671 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/composite"]
2013-10-23 22:51:48,671 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] parallel execution is enabled: false
2013-10-23 22:51:48,672 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] starting jobs: 3
2013-10-23 22:51:48,672 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] allocating threads: 1
2013-10-23 22:51:48,673 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (1/3)
2013-10-23 22:51:48,696 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2013-10-23 22:51:48,734 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2013-10-23 22:51:48,738 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:48,878 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local681282319_0001
2013-10-23 22:51:48,896 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:48,898 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local681282319_0001_m_000000_0
2013-10-23 22:51:48,922 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:48,925 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt
2013-10-23 22:51:48,926 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@11c0b8a0
2013-10-23 22:51:48,930 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:48,934 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:49,030 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:49,031 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:49,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:49,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,092 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:49,093 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2013-10-23 22:51:49,105 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:49,116 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:49,118 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local681282319_0001_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,122 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt:0+828
2013-10-23 22:51:49,122 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local681282319_0001_m_000000_0' done.
2013-10-23 22:51:49,122 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local681282319_0001_m_000000_0
2013-10-23 22:51:49,122 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:49,130 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,131 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,136 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:49,141 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 1818 bytes
2013-10-23 22:51:49,142 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,143 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:49,143 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,158 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2013-10-23 22:51:49,158 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6526002287/euclidean/]
2013-10-23 22:51:49,173 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:49,173 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:49,210 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local681282319_0001_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,211 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,211 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local681282319_0001_r_000000_0 is allowed to commit now
2013-10-23 22:51:49,214 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local681282319_0001_r_000000_0' to file:/tmp/hadoop-jwfbean/6526002287_euclidean_55FAE422AB28410AB5EA95A97B1A7F65
2013-10-23 22:51:49,215 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:49,215 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local681282319_0001_r_000000_0' done.
2013-10-23 22:51:49,227 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (2/3)
2013-10-23 22:51:49,238 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:49,301 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local1283615766_0002
2013-10-23 22:51:49,303 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:49,308 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1283615766_0002_m_000000_0
2013-10-23 22:51:49,310 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,312 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/6526002287_euclidean_55FAE422AB28410AB5EA95A97B1A7F65/part-00000
2013-10-23 22:51:49,312 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@73e492d8
2013-10-23 22:51:49,319 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:49,319 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:49,379 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:49,379 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:49,380 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:49,380 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6526002287/euclidean/]
2013-10-23 22:51:49,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2013-10-23 22:51:49,432 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:49,470 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:49,473 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1283615766_0002_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,475 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/6526002287_euclidean_55FAE422AB28410AB5EA95A97B1A7F65/part-00000:0+13816
2013-10-23 22:51:49,476 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1283615766_0002_m_000000_0' done.
2013-10-23 22:51:49,476 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1283615766_0002_m_000000_0
2013-10-23 22:51:49,476 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:49,480 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,481 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,481 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:49,482 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 13454 bytes
2013-10-23 22:51:49,483 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,483 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:49,483 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,493 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2013-10-23 22:51:49,493 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][4120473301/euclidean/]
2013-10-23 22:51:49,515 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1283615766_0002_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,516 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,516 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1283615766_0002_r_000000_0 is allowed to commit now
2013-10-23 22:51:49,518 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1283615766_0002_r_000000_0' to file:/tmp/hadoop-jwfbean/4120473301_euclidean_EE848FC5351540769284E51E5BC27637
2013-10-23 22:51:49,519 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:49,519 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1283615766_0002_r_000000_0' done.
2013-10-23 22:51:49,532 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (3/3) ...tform/euclidean/composite
2013-10-23 22:51:49,541 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:49,581 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local1861316187_0003
2013-10-23 22:51:49,583 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:49,583 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1861316187_0003_m_000000_0
2013-10-23 22:51:49,584 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,585 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/4120473301_euclidean_EE848FC5351540769284E51E5BC27637/part-00000
2013-10-23 22:51:49,585 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@20a83c2a
2013-10-23 22:51:49,587 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:49,587 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:49,646 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:49,646 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:49,648 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:49,648 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,657 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][4120473301/euclidean/]
2013-10-23 22:51:49,657 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2013-10-23 22:51:49,672 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:49,682 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:49,684 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1861316187_0003_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,686 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/4120473301_euclidean_EE848FC5351540769284E51E5BC27637/part-00000:0+6943
2013-10-23 22:51:49,686 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1861316187_0003_m_000000_0' done.
2013-10-23 22:51:49,686 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1861316187_0003_m_000000_0
2013-10-23 22:51:49,687 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:49,690 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,691 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,691 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:49,692 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 6467 bytes
2013-10-23 22:51:49,692 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,693 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:49,693 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,701 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2013-10-23 22:51:49,701 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/composite"]
2013-10-23 22:51:49,712 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1861316187_0003_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,714 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,714 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1861316187_0003_r_000000_0 is allowed to commit now
2013-10-23 22:51:49,716 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1861316187_0003_r_000000_0' to file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/composite
2013-10-23 22:51:49,717 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:49,717 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1861316187_0003_r_000000_0' done.
2013-10-23 22:51:49,726 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/composite/_temporary
2013-10-23 22:51:49,740 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:49,754 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:49,755 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output//hadoop/distanceusecaseplatform/euclidean/composite
2013-10-23 22:51:49,770 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-10-23 22:51:49,770 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /Users/jwfbean/.gradle/caches/artifacts-26/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-10-23 22:51:49,817 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [pearson] starting
2013-10-23 22:51:49,818 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [pearson] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:49,818 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [pearson] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/pearson/composite"]
2013-10-23 22:51:49,818 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [pearson] parallel execution is enabled: false
2013-10-23 22:51:49,818 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [pearson] starting jobs: 3
2013-10-23 22:51:49,818 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [pearson] allocating threads: 1
2013-10-23 22:51:49,818 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [pearson] starting step: (1/3)
2013-10-23 22:51:49,828 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:49,858 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [pearson] submitted hadoop job: job_local1356510217_0004
2013-10-23 22:51:49,860 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:49,860 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1356510217_0004_m_000000_0
2013-10-23 22:51:49,861 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,862 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt
2013-10-23 22:51:49,863 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@44c6b80e
2013-10-23 22:51:49,864 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:49,864 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:49,924 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:49,924 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:49,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:49,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,935 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:49,935 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2013-10-23 22:51:49,938 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:49,940 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:49,941 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1356510217_0004_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,943 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt:0+828
2013-10-23 22:51:49,943 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1356510217_0004_m_000000_0' done.
2013-10-23 22:51:49,943 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1356510217_0004_m_000000_0
2013-10-23 22:51:49,943 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:49,946 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:49,946 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,946 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:49,947 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 1818 bytes
2013-10-23 22:51:49,947 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,947 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:49,947 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:49,956 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2013-10-23 22:51:49,956 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][616384302/pearson/]
2013-10-23 22:51:49,959 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:49,959 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:49,980 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1356510217_0004_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:49,981 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:49,981 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1356510217_0004_r_000000_0 is allowed to commit now
2013-10-23 22:51:49,983 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1356510217_0004_r_000000_0' to file:/tmp/hadoop-jwfbean/616384302_pearson_7E46D487892A458B9847F6228843D7CB
2013-10-23 22:51:49,983 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:49,984 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1356510217_0004_r_000000_0' done.
2013-10-23 22:51:49,990 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [pearson] starting step: (2/3)
2013-10-23 22:51:49,999 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,025 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [pearson] submitted hadoop job: job_local679016940_0005
2013-10-23 22:51:50,026 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:50,026 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local679016940_0005_m_000000_0
2013-10-23 22:51:50,027 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,028 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/616384302_pearson_7E46D487892A458B9847F6228843D7CB/part-00000
2013-10-23 22:51:50,028 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@5492de02
2013-10-23 22:51:50,029 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:50,030 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:50,089 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:50,089 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:50,090 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:50,090 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,097 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][616384302/pearson/]
2013-10-23 22:51:50,098 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2013-10-23 22:51:50,108 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:50,116 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:50,117 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local679016940_0005_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,119 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/616384302_pearson_7E46D487892A458B9847F6228843D7CB/part-00000:0+13816
2013-10-23 22:51:50,119 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local679016940_0005_m_000000_0' done.
2013-10-23 22:51:50,119 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local679016940_0005_m_000000_0
2013-10-23 22:51:50,119 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:50,121 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,122 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,122 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:50,122 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 13454 bytes
2013-10-23 22:51:50,123 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,123 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:50,123 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,129 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2013-10-23 22:51:50,129 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6055956163/pearson/]
2013-10-23 22:51:50,142 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local679016940_0005_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,143 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,143 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local679016940_0005_r_000000_0 is allowed to commit now
2013-10-23 22:51:50,144 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local679016940_0005_r_000000_0' to file:/tmp/hadoop-jwfbean/6055956163_pearson_40B19E55146F4229A2523C50E9277C6A
2013-10-23 22:51:50,145 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:50,145 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local679016940_0005_r_000000_0' done.
2013-10-23 22:51:50,154 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [pearson] starting step: (3/3) ...latform/pearson/composite
2013-10-23 22:51:50,163 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,187 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [pearson] submitted hadoop job: job_local22016491_0006
2013-10-23 22:51:50,188 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:50,189 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local22016491_0006_m_000000_0
2013-10-23 22:51:50,190 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,190 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/6055956163_pearson_40B19E55146F4229A2523C50E9277C6A/part-00000
2013-10-23 22:51:50,191 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1adbbe8b
2013-10-23 22:51:50,191 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:50,192 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:50,251 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:50,251 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:50,252 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:50,252 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,259 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6055956163/pearson/]
2013-10-23 22:51:50,259 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2013-10-23 22:51:50,264 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:50,267 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:50,268 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local22016491_0006_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,270 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/6055956163_pearson_40B19E55146F4229A2523C50E9277C6A/part-00000:0+6943
2013-10-23 22:51:50,270 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local22016491_0006_m_000000_0' done.
2013-10-23 22:51:50,270 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local22016491_0006_m_000000_0
2013-10-23 22:51:50,270 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:50,273 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,273 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,274 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:50,274 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 6467 bytes
2013-10-23 22:51:50,275 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,275 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:50,275 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,282 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2013-10-23 22:51:50,282 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/pearson/composite"]
2013-10-23 22:51:50,292 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local22016491_0006_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,293 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,293 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local22016491_0006_r_000000_0 is allowed to commit now
2013-10-23 22:51:50,295 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local22016491_0006_r_000000_0' to file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/pearson/composite
2013-10-23 22:51:50,296 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:50,296 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local22016491_0006_r_000000_0' done.
2013-10-23 22:51:50,305 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/pearson/composite/_temporary
2013-10-23 22:51:50,313 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,323 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,325 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output//hadoop/distanceusecaseplatform/pearson/composite
2013-10-23 22:51:50,335 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-10-23 22:51:50,336 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /Users/jwfbean/.gradle/caches/artifacts-26/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-10-23 22:51:50,377 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] starting
2013-10-23 22:51:50,378 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:50,378 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/long"]
2013-10-23 22:51:50,378 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] parallel execution is enabled: false
2013-10-23 22:51:50,378 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] starting jobs: 3
2013-10-23 22:51:50,378 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] allocating threads: 1
2013-10-23 22:51:50,379 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (1/3)
2013-10-23 22:51:50,387 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,410 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local1695835278_0007
2013-10-23 22:51:50,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:50,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1695835278_0007_m_000000_0
2013-10-23 22:51:50,412 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,414 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt
2013-10-23 22:51:50,414 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@18d210ab
2013-10-23 22:51:50,415 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:50,416 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:50,478 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:50,478 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:50,479 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:50,480 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,488 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:50,488 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2013-10-23 22:51:50,491 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:50,493 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:50,495 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1695835278_0007_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,497 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt:0+828
2013-10-23 22:51:50,497 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1695835278_0007_m_000000_0' done.
2013-10-23 22:51:50,497 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1695835278_0007_m_000000_0
2013-10-23 22:51:50,497 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:50,500 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,500 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,500 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:50,501 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 1818 bytes
2013-10-23 22:51:50,501 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:50,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,507 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2013-10-23 22:51:50,507 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][4631408099/euclidean/]
2013-10-23 22:51:50,510 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:50,510 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:50,524 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1695835278_0007_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,525 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,525 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1695835278_0007_r_000000_0 is allowed to commit now
2013-10-23 22:51:50,526 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1695835278_0007_r_000000_0' to file:/tmp/hadoop-jwfbean/4631408099_euclidean_5C82C0C0A17D476D870AFF1C3D033608
2013-10-23 22:51:50,527 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:50,527 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1695835278_0007_r_000000_0' done.
2013-10-23 22:51:50,532 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (2/3)
2013-10-23 22:51:50,539 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,559 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local644370700_0008
2013-10-23 22:51:50,561 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:50,561 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local644370700_0008_m_000000_0
2013-10-23 22:51:50,562 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,563 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/4631408099_euclidean_5C82C0C0A17D476D870AFF1C3D033608/part-00000
2013-10-23 22:51:50,563 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@13ab6c1c
2013-10-23 22:51:50,565 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:50,565 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:50,624 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:50,624 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:50,625 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:50,625 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,631 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][4631408099/euclidean/]
2013-10-23 22:51:50,631 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2013-10-23 22:51:50,637 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:50,644 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:50,646 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local644370700_0008_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,647 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/4631408099_euclidean_5C82C0C0A17D476D870AFF1C3D033608/part-00000:0+13816
2013-10-23 22:51:50,647 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local644370700_0008_m_000000_0' done.
2013-10-23 22:51:50,647 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local644370700_0008_m_000000_0
2013-10-23 22:51:50,648 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:50,650 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,650 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,650 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:50,651 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 13454 bytes
2013-10-23 22:51:50,651 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,651 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:50,651 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,657 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2013-10-23 22:51:50,657 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8073124569/euclidean/]
2013-10-23 22:51:50,671 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local644370700_0008_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,672 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,672 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local644370700_0008_r_000000_0 is allowed to commit now
2013-10-23 22:51:50,674 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local644370700_0008_r_000000_0' to file:/tmp/hadoop-jwfbean/8073124569_euclidean_DA73A585E2C04A9892F112C3E5475680
2013-10-23 22:51:50,674 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:50,674 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local644370700_0008_r_000000_0' done.
2013-10-23 22:51:50,678 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (3/3) ...seplatform/euclidean/long
2013-10-23 22:51:50,685 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,708 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local2070636646_0009
2013-10-23 22:51:50,709 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:50,709 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local2070636646_0009_m_000000_0
2013-10-23 22:51:50,710 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,711 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/8073124569_euclidean_DA73A585E2C04A9892F112C3E5475680/part-00000
2013-10-23 22:51:50,711 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@79fb80c9
2013-10-23 22:51:50,712 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:50,712 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:50,774 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:50,774 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:50,775 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:50,775 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,781 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8073124569/euclidean/]
2013-10-23 22:51:50,781 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2013-10-23 22:51:50,786 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:50,789 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:50,790 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local2070636646_0009_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,792 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/8073124569_euclidean_DA73A585E2C04A9892F112C3E5475680/part-00000:0+7726
2013-10-23 22:51:50,792 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local2070636646_0009_m_000000_0' done.
2013-10-23 22:51:50,792 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local2070636646_0009_m_000000_0
2013-10-23 22:51:50,792 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:50,794 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,794 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,795 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:50,795 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 7250 bytes
2013-10-23 22:51:50,795 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,796 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:50,796 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,801 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2013-10-23 22:51:50,802 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/long"]
2013-10-23 22:51:50,808 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local2070636646_0009_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,809 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,809 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local2070636646_0009_r_000000_0 is allowed to commit now
2013-10-23 22:51:50,811 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local2070636646_0009_r_000000_0' to file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/long
2013-10-23 22:51:50,812 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:50,812 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local2070636646_0009_r_000000_0' done.
2013-10-23 22:51:50,819 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/long/_temporary
2013-10-23 22:51:50,827 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,837 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,838 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output//hadoop/distanceusecaseplatform/euclidean/long
2013-10-23 22:51:50,846 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-10-23 22:51:50,846 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /Users/jwfbean/.gradle/caches/artifacts-26/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-10-23 22:51:50,877 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] starting
2013-10-23 22:51:50,877 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:50,878 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/short"]
2013-10-23 22:51:50,878 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] parallel execution is enabled: false
2013-10-23 22:51:50,878 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] starting jobs: 3
2013-10-23 22:51:50,878 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [euclidean] allocating threads: 1
2013-10-23 22:51:50,878 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (1/3)
2013-10-23 22:51:50,888 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:50,906 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local1731097550_0010
2013-10-23 22:51:50,907 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:50,907 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1731097550_0010_m_000000_0
2013-10-23 22:51:50,908 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,909 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt
2013-10-23 22:51:50,909 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@13a66c87
2013-10-23 22:51:50,910 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:50,910 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:50,969 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:50,969 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:50,970 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:50,970 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,974 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt"]
2013-10-23 22:51:50,975 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2013-10-23 22:51:50,977 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:50,978 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:50,979 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1731097550_0010_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:50,980 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/classes/test/data/critics.txt:0+828
2013-10-23 22:51:50,980 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1731097550_0010_m_000000_0' done.
2013-10-23 22:51:50,981 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1731097550_0010_m_000000_0
2013-10-23 22:51:50,981 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:50,983 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:50,983 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,983 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:50,984 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 1818 bytes
2013-10-23 22:51:50,984 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:50,984 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:50,984 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:50,989 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2013-10-23 22:51:50,989 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][4566385458/euclidean/]
2013-10-23 22:51:50,991 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:50,991 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2013-10-23 22:51:51,005 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1731097550_0010_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:51,006 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,006 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1731097550_0010_r_000000_0 is allowed to commit now
2013-10-23 22:51:51,008 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1731097550_0010_r_000000_0' to file:/tmp/hadoop-jwfbean/4566385458_euclidean_4974D949F28241E9A9518381CC994A2A
2013-10-23 22:51:51,009 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:51,009 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1731097550_0010_r_000000_0' done.
2013-10-23 22:51:51,012 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (2/3)
2013-10-23 22:51:51,020 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:51,037 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local968491489_0011
2013-10-23 22:51:51,038 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:51,038 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local968491489_0011_m_000000_0
2013-10-23 22:51:51,039 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:51,039 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/4566385458_euclidean_4974D949F28241E9A9518381CC994A2A/part-00000
2013-10-23 22:51:51,040 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1a752144
2013-10-23 22:51:51,040 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:51,041 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:51,102 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:51,103 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:51,103 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:51,104 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:51,109 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][4566385458/euclidean/]
2013-10-23 22:51:51,109 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2013-10-23 22:51:51,116 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:51,120 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:51,121 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local968491489_0011_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:51,122 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/4566385458_euclidean_4974D949F28241E9A9518381CC994A2A/part-00000:0+13816
2013-10-23 22:51:51,123 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local968491489_0011_m_000000_0' done.
2013-10-23 22:51:51,123 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local968491489_0011_m_000000_0
2013-10-23 22:51:51,123 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:51,125 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:51,125 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,126 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:51,126 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 13454 bytes
2013-10-23 22:51:51,126 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,126 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:51,127 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:51,131 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2013-10-23 22:51:51,131 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][2790104052/euclidean/]
2013-10-23 22:51:51,143 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local968491489_0011_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:51,144 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,144 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local968491489_0011_r_000000_0 is allowed to commit now
2013-10-23 22:51:51,147 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local968491489_0011_r_000000_0' to file:/tmp/hadoop-jwfbean/2790104052_euclidean_C75C56CFDDA34736B5F212F9D8FB9E0C
2013-10-23 22:51:51,147 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:51,148 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local968491489_0011_r_000000_0' done.
2013-10-23 22:51:51,158 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] starting step: (3/3) ...eplatform/euclidean/short
2013-10-23 22:51:51,166 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:51,185 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [euclidean] submitted hadoop job: job_local1875994963_0012
2013-10-23 22:51:51,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-10-23 22:51:51,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1875994963_0012_m_000000_0
2013-10-23 22:51:51,187 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:51,188 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-jwfbean/2790104052_euclidean_C75C56CFDDA34736B5F212F9D8FB9E0C/part-00000
2013-10-23 22:51:51,189 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@5513dd59
2013-10-23 22:51:51,190 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-10-23 22:51:51,190 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-10-23 22:51:51,250 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-10-23 22:51:51,250 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-10-23 22:51:51,251 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-10-23 22:51:51,251 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-10-23 22:51:51,256 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][2790104052/euclidean/]
2013-10-23 22:51:51,256 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2013-10-23 22:51:51,260 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-10-23 22:51:51,262 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-10-23 22:51:51,264 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1875994963_0012_m_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:51,265 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/tmp/hadoop-jwfbean/2790104052_euclidean_C75C56CFDDA34736B5F212F9D8FB9E0C/part-00000:0+7726
2013-10-23 22:51:51,265 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1875994963_0012_m_000000_0' done.
2013-10-23 22:51:51,265 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1875994963_0012_m_000000_0
2013-10-23 22:51:51,265 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-10-23 22:51:51,267 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : null
2013-10-23 22:51:51,268 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,268 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-10-23 22:51:51,268 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 7250 bytes
2013-10-23 22:51:51,269 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,269 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-10-23 22:51:51,269 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-10-23 22:51:51,274 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2013-10-23 22:51:51,274 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/short"]
2013-10-23 22:51:51,281 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1875994963_0012_r_000000_0 is done. And is in the process of commiting
2013-10-23 22:51:51,282 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-10-23 22:51:51,282 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1875994963_0012_r_000000_0 is allowed to commit now
2013-10-23 22:51:51,284 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1875994963_0012_r_000000_0' to file:/Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/short
2013-10-23 22:51:51,285 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-10-23 22:51:51,285 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1875994963_0012_r_000000_0' done.
2013-10-23 22:51:51,295 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output/hadoop/distanceusecaseplatform/euclidean/short/_temporary
2013-10-23 22:51:51,302 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:51,310 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-10-23 22:51:51,311 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/jwfbean/git/cascading.compatibility/cloudera-cdh4.4/build/test/output//hadoop/distanceusecaseplatform/euclidean/short