2016-01-14 21:22:02,652 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 21:22:02,668 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.DistanceUseCasePlatformTest, with platform: hadoop
2016-01-14 21:22:02,691 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-01-14 21:22:02,915 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 21:22:03,020 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:22:03,022 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 21:22:03,123 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 28662E0284BE4890BB7E29A69CC2C76C
2016-01-14 21:22:03,437 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.269
2016-01-14 21:22:03,443 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-01-14 21:22:03,444 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:22:03,675 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 21:22:03,677 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting
2016-01-14 21:22:03,678 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:03,678 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite"]
2016-01-14 21:22:03,679 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] parallel execution of steps is enabled: false
2016-01-14 21:22:03,680 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] executing total steps: 3
2016-01-14 21:22:03,680 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] allocating management threads: 1
2016-01-14 21:22:03,681 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (1/3)
2016-01-14 21:22:03,715 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 21:22:03,763 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-01-14 21:22:04,005 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0001
2016-01-14 21:22:04,007 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:04,072 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt
2016-01-14 21:22:04,208 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:04,208 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:04,235 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D447E910DA9D46159AEEE1C0E0DBD2A9, ordinal: 0
2016-01-14 21:22:04,285 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:04,285 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2016-01-14 21:22:04,286 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D447E910DA9D46159AEEE1C0E0DBD2A9, mem on start (mb), free: 78, total: 223, max: 672
2016-01-14 21:22:04,304 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D447E910DA9D46159AEEE1C0E0DBD2A9, mem on close (mb), free: 77, total: 223, max: 672
2016-01-14 21:22:04,336 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:04,337 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:04,354 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B5DB9857742640B89991B3F65A9D597D, ordinal: 1
2016-01-14 21:22:04,358 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2016-01-14 21:22:04,359 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][7483810343/euclidean/]
2016-01-14 21:22:04,359 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B5DB9857742640B89991B3F65A9D597D, mem on start (mb), free: 75, total: 223, max: 672
2016-01-14 21:22:04,378 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:04,379 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:04,418 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B5DB9857742640B89991B3F65A9D597D, mem on close (mb), free: 73, total: 223, max: 672
2016-01-14 21:22:04,435 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (2/3)
2016-01-14 21:22:04,521 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0002
2016-01-14 21:22:04,521 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:04,526 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/7483810343_euclidean_8C72CEE3CF5A434CA419AD92E954F9E6/part-00000
2016-01-14 21:22:04,633 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:04,634 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:04,646 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B6A7FBFD1D1A455D90175AF0A2C2169B, ordinal: 0
2016-01-14 21:22:04,647 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][7483810343/euclidean/]
2016-01-14 21:22:04,647 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-01-14 21:22:04,647 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B6A7FBFD1D1A455D90175AF0A2C2169B, mem on start (mb), free: 62, total: 318, max: 672
2016-01-14 21:22:04,688 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B6A7FBFD1D1A455D90175AF0A2C2169B, mem on close (mb), free: 62, total: 318, max: 672
2016-01-14 21:22:04,747 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:04,748 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:04,762 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E68158385144493FB9DEED4D6CF65FAF, ordinal: 1
2016-01-14 21:22:04,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-01-14 21:22:04,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][3103124053/euclidean/]
2016-01-14 21:22:04,765 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E68158385144493FB9DEED4D6CF65FAF, mem on start (mb), free: 176, total: 377, max: 672
2016-01-14 21:22:04,789 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E68158385144493FB9DEED4D6CF65FAF, mem on close (mb), free: 176, total: 377, max: 672
2016-01-14 21:22:04,798 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (3/3) ...osite/euclidean/composite
2016-01-14 21:22:04,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0003
2016-01-14 21:22:04,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:04,861 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3103124053_euclidean_99F56F20AD344E9EA4630852D713966D/part-00000
2016-01-14 21:22:04,917 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:04,918 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:04,929 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FE4EB725A6F746A183A0F24ECF3B8878, ordinal: 0
2016-01-14 21:22:04,930 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][3103124053/euclidean/]
2016-01-14 21:22:04,931 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2016-01-14 21:22:04,932 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FE4EB725A6F746A183A0F24ECF3B8878, mem on start (mb), free: 70, total: 377, max: 672
2016-01-14 21:22:04,955 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FE4EB725A6F746A183A0F24ECF3B8878, mem on close (mb), free: 70, total: 377, max: 672
2016-01-14 21:22:04,981 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:04,982 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:04,999 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AAB5A4A06A51460BBE052E0FB220574E, ordinal: 1
2016-01-14 21:22:05,000 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2016-01-14 21:22:05,001 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite"]
2016-01-14 21:22:05,001 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AAB5A4A06A51460BBE052E0FB220574E, mem on start (mb), free: 69, total: 377, max: 672
2016-01-14 21:22:05,023 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AAB5A4A06A51460BBE052E0FB220574E, mem on close (mb), free: 68, total: 377, max: 672
2016-01-14 21:22:05,043 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite/_temporary
2016-01-14 21:22:05,045 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] completed in: 00:01.362
2016-01-14 21:22:05,101 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite
2016-01-14 21:22:05,132 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:22:05,133 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 21:22:05,353 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.200
2016-01-14 21:22:05,355 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-01-14 21:22:05,356 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:22:05,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] starting
2016-01-14 21:22:05,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:05,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite"]
2016-01-14 21:22:05,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] parallel execution of steps is enabled: false
2016-01-14 21:22:05,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] executing total steps: 3
2016-01-14 21:22:05,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] allocating management threads: 1
2016-01-14 21:22:05,418 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] starting step: (1/3)
2016-01-14 21:22:05,465 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] submitted hadoop job: job_local_0004
2016-01-14 21:22:05,466 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] tracking url: http://localhost:8080/
2016-01-14 21:22:05,469 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt
2016-01-14 21:22:05,485 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:05,485 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:05,495 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BA096BD827A34DCC9947C362C3628E65, ordinal: 0
2016-01-14 21:22:05,496 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:05,497 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2016-01-14 21:22:05,497 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BA096BD827A34DCC9947C362C3628E65, mem on start (mb), free: 67, total: 377, max: 672
2016-01-14 21:22:05,501 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BA096BD827A34DCC9947C362C3628E65, mem on close (mb), free: 67, total: 377, max: 672
2016-01-14 21:22:05,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:05,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:05,520 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E64FE9E658424B6BAFE9F7EB31BC2BC1, ordinal: 1
2016-01-14 21:22:05,521 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2016-01-14 21:22:05,522 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][2832953573/pearson/]
2016-01-14 21:22:05,522 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E64FE9E658424B6BAFE9F7EB31BC2BC1, mem on start (mb), free: 66, total: 377, max: 672
2016-01-14 21:22:05,525 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:05,526 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:05,558 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E64FE9E658424B6BAFE9F7EB31BC2BC1, mem on close (mb), free: 65, total: 377, max: 672
2016-01-14 21:22:05,569 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] starting step: (2/3)
2016-01-14 21:22:05,620 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] submitted hadoop job: job_local_0005
2016-01-14 21:22:05,620 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] tracking url: http://localhost:8080/
2016-01-14 21:22:05,623 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/2832953573_pearson_80DCA9D87E62452D968C57963E2EFDD4/part-00000
2016-01-14 21:22:05,637 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:05,638 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:05,646 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EB41F3771FBB4C08810CD248B3320AAA, ordinal: 0
2016-01-14 21:22:05,646 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][2832953573/pearson/]
2016-01-14 21:22:05,647 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2016-01-14 21:22:05,647 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EB41F3771FBB4C08810CD248B3320AAA, mem on start (mb), free: 190, total: 493, max: 672
2016-01-14 21:22:05,661 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EB41F3771FBB4C08810CD248B3320AAA, mem on close (mb), free: 190, total: 493, max: 672
2016-01-14 21:22:05,684 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:05,684 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:05,697 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F0FB52FD8AC24AFEB0E66B17E89ED3D7, ordinal: 1
2016-01-14 21:22:05,698 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2016-01-14 21:22:05,698 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1378278289/pearson/]
2016-01-14 21:22:05,699 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F0FB52FD8AC24AFEB0E66B17E89ED3D7, mem on start (mb), free: 186, total: 493, max: 672
2016-01-14 21:22:05,717 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F0FB52FD8AC24AFEB0E66B17E89ED3D7, mem on close (mb), free: 186, total: 493, max: 672
2016-01-14 21:22:05,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] starting step: (3/3) ...mposite/pearson/composite
2016-01-14 21:22:05,760 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] submitted hadoop job: job_local_0006
2016-01-14 21:22:05,760 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] tracking url: http://localhost:8080/
2016-01-14 21:22:05,763 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/1378278289_pearson_834E96B4A248475EADF5F6E3E62CF000/part-00000
2016-01-14 21:22:05,853 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:05,854 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:05,862 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DCB2C83C84714735AF8DD10EA4B85006, ordinal: 0
2016-01-14 21:22:05,862 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][1378278289/pearson/]
2016-01-14 21:22:05,863 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2016-01-14 21:22:05,863 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DCB2C83C84714735AF8DD10EA4B85006, mem on start (mb), free: 80, total: 493, max: 672
2016-01-14 21:22:05,870 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DCB2C83C84714735AF8DD10EA4B85006, mem on close (mb), free: 80, total: 493, max: 672
2016-01-14 21:22:05,880 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:05,880 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:05,889 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FC6BDAA83BD14E68A6972F58184F6583, ordinal: 1
2016-01-14 21:22:05,890 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2016-01-14 21:22:05,890 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite"]
2016-01-14 21:22:05,891 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FC6BDAA83BD14E68A6972F58184F6583, mem on start (mb), free: 78, total: 493, max: 672
2016-01-14 21:22:05,903 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FC6BDAA83BD14E68A6972F58184F6583, mem on close (mb), free: 77, total: 493, max: 672
2016-01-14 21:22:05,920 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite/_temporary
2016-01-14 21:22:05,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pearson] completed in: 00:00.503
2016-01-14 21:22:05,943 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite
2016-01-14 21:22:05,960 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:22:05,961 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 21:22:06,103 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.137
2016-01-14 21:22:06,106 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-01-14 21:22:06,107 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:22:06,215 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting
2016-01-14 21:22:06,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:06,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long"]
2016-01-14 21:22:06,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] parallel execution of steps is enabled: false
2016-01-14 21:22:06,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] executing total steps: 3
2016-01-14 21:22:06,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] allocating management threads: 1
2016-01-14 21:22:06,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (1/3)
2016-01-14 21:22:06,265 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0007
2016-01-14 21:22:06,266 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:06,272 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt
2016-01-14 21:22:06,288 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:06,289 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,299 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DB47489EDC414AE9ADCBABF0D6C5326A, ordinal: 0
2016-01-14 21:22:06,300 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:06,301 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-01-14 21:22:06,301 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DB47489EDC414AE9ADCBABF0D6C5326A, mem on start (mb), free: 187, total: 493, max: 672
2016-01-14 21:22:06,316 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DB47489EDC414AE9ADCBABF0D6C5326A, mem on close (mb), free: 187, total: 493, max: 672
2016-01-14 21:22:06,330 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:06,330 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,341 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A1D5778FD06B41B7B67DF530258CF741, ordinal: 1
2016-01-14 21:22:06,342 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-01-14 21:22:06,342 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][5107180240/euclidean/]
2016-01-14 21:22:06,343 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A1D5778FD06B41B7B67DF530258CF741, mem on start (mb), free: 185, total: 493, max: 672
2016-01-14 21:22:06,347 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:06,347 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:06,374 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A1D5778FD06B41B7B67DF530258CF741, mem on close (mb), free: 185, total: 493, max: 672
2016-01-14 21:22:06,384 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (2/3)
2016-01-14 21:22:06,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0008
2016-01-14 21:22:06,422 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:06,427 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5107180240_euclidean_39B00E634C974475A809979AA406755E/part-00000
2016-01-14 21:22:06,445 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:06,446 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,456 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B8A942B7F2A64F129884B11A1997272B, ordinal: 0
2016-01-14 21:22:06,457 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][5107180240/euclidean/]
2016-01-14 21:22:06,457 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-01-14 21:22:06,457 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8A942B7F2A64F129884B11A1997272B, mem on start (mb), free: 78, total: 493, max: 672
2016-01-14 21:22:06,472 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8A942B7F2A64F129884B11A1997272B, mem on close (mb), free: 78, total: 493, max: 672
2016-01-14 21:22:06,491 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:06,492 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,499 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DDE64BC1428D4CCA88C8A7CEB634432B, ordinal: 1
2016-01-14 21:22:06,500 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-01-14 21:22:06,500 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][5304129593/euclidean/]
2016-01-14 21:22:06,500 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DDE64BC1428D4CCA88C8A7CEB634432B, mem on start (mb), free: 74, total: 493, max: 672
2016-01-14 21:22:06,522 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DDE64BC1428D4CCA88C8A7CEB634432B, mem on close (mb), free: 69, total: 493, max: 672
2016-01-14 21:22:06,535 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (3/3) ...anDistance/euclidean/long
2016-01-14 21:22:06,564 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0009
2016-01-14 21:22:06,567 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:06,572 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5304129593_euclidean_EDA53DFA24114092A9B0DA1C0353CF0D/part-00000
2016-01-14 21:22:06,602 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:06,604 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,614 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F84F8EA73D1C4858A28B197E57D4FE78, ordinal: 0
2016-01-14 21:22:06,615 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][5304129593/euclidean/]
2016-01-14 21:22:06,616 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-01-14 21:22:06,616 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F84F8EA73D1C4858A28B197E57D4FE78, mem on start (mb), free: 196, total: 493, max: 672
2016-01-14 21:22:06,625 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F84F8EA73D1C4858A28B197E57D4FE78, mem on close (mb), free: 196, total: 493, max: 672
2016-01-14 21:22:06,638 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:06,638 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,650 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C1406125E2E44171B9176777836A2FFD, ordinal: 1
2016-01-14 21:22:06,651 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-01-14 21:22:06,652 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long"]
2016-01-14 21:22:06,652 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C1406125E2E44171B9176777836A2FFD, mem on start (mb), free: 193, total: 493, max: 672
2016-01-14 21:22:06,664 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C1406125E2E44171B9176777836A2FFD, mem on close (mb), free: 192, total: 493, max: 672
2016-01-14 21:22:06,678 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long/_temporary
2016-01-14 21:22:06,679 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] completed in: 00:00.462
2016-01-14 21:22:06,698 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long
2016-01-14 21:22:06,709 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:22:06,709 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 21:22:06,803 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.090
2016-01-14 21:22:06,805 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-01-14 21:22:06,806 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:22:06,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting
2016-01-14 21:22:06,856 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:06,857 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short"]
2016-01-14 21:22:06,857 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] parallel execution of steps is enabled: false
2016-01-14 21:22:06,857 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] executing total steps: 3
2016-01-14 21:22:06,858 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] allocating management threads: 1
2016-01-14 21:22:06,859 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (1/3)
2016-01-14 21:22:06,894 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0010
2016-01-14 21:22:06,894 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:06,898 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt
2016-01-14 21:22:06,913 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:06,913 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,919 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: ABC1942BBCE44C369045502B1E4E1C7C, ordinal: 0
2016-01-14 21:22:06,920 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/critics.txt"]
2016-01-14 21:22:06,920 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-01-14 21:22:06,920 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ABC1942BBCE44C369045502B1E4E1C7C, mem on start (mb), free: 73, total: 493, max: 672
2016-01-14 21:22:06,924 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ABC1942BBCE44C369045502B1E4E1C7C, mem on close (mb), free: 73, total: 493, max: 672
2016-01-14 21:22:06,932 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:06,932 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:06,938 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F4C93C464C0740D5AA8791E387328576, ordinal: 1
2016-01-14 21:22:06,938 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-01-14 21:22:06,938 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][4694386016/euclidean/]
2016-01-14 21:22:06,939 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F4C93C464C0740D5AA8791E387328576, mem on start (mb), free: 71, total: 493, max: 672
2016-01-14 21:22:06,941 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:06,942 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 21:22:06,963 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F4C93C464C0740D5AA8791E387328576, mem on close (mb), free: 70, total: 493, max: 672
2016-01-14 21:22:06,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (2/3)
2016-01-14 21:22:07,003 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0011
2016-01-14 21:22:07,004 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:07,007 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4694386016_euclidean_49B598ECF2DC4E33AFB10860607CCD86/part-00000
2016-01-14 21:22:07,037 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:07,037 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:07,043 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CC85FAAAC8A6461EBC46B4B02F37B7D2, ordinal: 0
2016-01-14 21:22:07,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][4694386016/euclidean/]
2016-01-14 21:22:07,044 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-01-14 21:22:07,044 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC85FAAAC8A6461EBC46B4B02F37B7D2, mem on start (mb), free: 188, total: 485, max: 672
2016-01-14 21:22:07,054 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC85FAAAC8A6461EBC46B4B02F37B7D2, mem on close (mb), free: 187, total: 485, max: 672
2016-01-14 21:22:07,064 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:07,064 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:07,070 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BE8BA74C51DC4D92A6A647E2BEBFC4AF, ordinal: 1
2016-01-14 21:22:07,071 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-01-14 21:22:07,071 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8449278242/euclidean/]
2016-01-14 21:22:07,071 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BE8BA74C51DC4D92A6A647E2BEBFC4AF, mem on start (mb), free: 184, total: 485, max: 672
2016-01-14 21:22:07,090 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BE8BA74C51DC4D92A6A647E2BEBFC4AF, mem on close (mb), free: 184, total: 485, max: 672
2016-01-14 21:22:07,097 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] starting step: (3/3) ...anceShort/euclidean/short
2016-01-14 21:22:07,130 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] submitted hadoop job: job_local_0012
2016-01-14 21:22:07,131 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] tracking url: http://localhost:8080/
2016-01-14 21:22:07,137 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8449278242_euclidean_1BC0CD0490264807BADF39BB543109D2/part-00000
2016-01-14 21:22:07,154 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:07,154 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:07,159 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DF9CCF0872DA4DB29EE95107CFFA675C, ordinal: 0
2016-01-14 21:22:07,160 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8449278242/euclidean/]
2016-01-14 21:22:07,160 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-01-14 21:22:07,160 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF9CCF0872DA4DB29EE95107CFFA675C, mem on start (mb), free: 78, total: 485, max: 672
2016-01-14 21:22:07,165 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF9CCF0872DA4DB29EE95107CFFA675C, mem on close (mb), free: 78, total: 485, max: 672
2016-01-14 21:22:07,174 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:07,174 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:07,180 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DF23FF44538749A3903480ED8F0F5A2D, ordinal: 1
2016-01-14 21:22:07,180 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-01-14 21:22:07,181 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short"]
2016-01-14 21:22:07,181 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DF23FF44538749A3903480ED8F0F5A2D, mem on start (mb), free: 75, total: 485, max: 672
2016-01-14 21:22:07,192 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DF23FF44538749A3903480ED8F0F5A2D, mem on close (mb), free: 74, total: 485, max: 672
2016-01-14 21:22:07,205 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short/_temporary
2016-01-14 21:22:07,206 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [euclidean] completed in: 00:00.349
2016-01-14 21:22:07,223 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short