2016-05-18 00:25:28,166 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 00:25:28,182 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.DistanceUseCasePlatformTest, with platform: hadoop
2016-05-18 00:25:28,205 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 00:25:28,441 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 00:25:28,549 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:25:28,551 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 00:25:28,647 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 27FCF79A27F24DB3858FF2CAD6DB7C3B
2016-05-18 00:25:28,949 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.258
2016-05-18 00:25:28,953 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 00:25:28,954 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:25:29,179 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 00:25:29,180 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting
2016-05-18 00:25:29,181 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:25:29,181 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite"]
2016-05-18 00:25:29,181 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] parallel execution of steps is enabled: false
2016-05-18 00:25:29,182 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executing total steps: 3
2016-05-18 00:25:29,183 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] allocating management threads: 1
2016-05-18 00:25:29,184 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (1/3)
2016-05-18 00:25:29,231 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 00:25:29,277 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 00:25:29,488 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0001
2016-05-18 00:25:29,489 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:25:29,552 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt
2016-05-18 00:25:29,702 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:29,702 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:29,722 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B8C5E706E5434CB18D1AD2DA1AEB94BE, ordinal: 0
2016-05-18 00:25:29,760 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:25:29,760 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 00:25:29,761 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8C5E706E5434CB18D1AD2DA1AEB94BE, mem on start (mb), free: 80, total: 223, max: 672
2016-05-18 00:25:29,782 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8C5E706E5434CB18D1AD2DA1AEB94BE, mem on close (mb), free: 80, total: 223, max: 672
2016-05-18 00:25:32,545 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:32,545 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:32,567 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F527EB4F1EBB44AE8BBAABB23CBD9917, ordinal: 1
2016-05-18 00:25:32,570 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 00:25:32,570 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][5238344967/euclidean/]
2016-05-18 00:25:32,570 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F527EB4F1EBB44AE8BBAABB23CBD9917, mem on start (mb), free: 78, total: 223, max: 672
2016-05-18 00:25:32,592 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:25:32,592 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:25:32,632 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F527EB4F1EBB44AE8BBAABB23CBD9917, mem on close (mb), free: 76, total: 223, max: 672
2016-05-18 00:25:35,543 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (2/3)
2016-05-18 00:25:35,627 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0002
2016-05-18 00:25:35,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:25:35,634 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5238344967_euclidean_8A9BC377A6EE460A8E71F5C3467B85F4/part-00000
2016-05-18 00:25:35,771 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:35,771 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:35,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BB1CCAA59FEF4C2282B4773D4CF5775B, ordinal: 0
2016-05-18 00:25:35,790 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][5238344967/euclidean/]
2016-05-18 00:25:35,791 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 00:25:35,791 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB1CCAA59FEF4C2282B4773D4CF5775B, mem on start (mb), free: 67, total: 318, max: 672
2016-05-18 00:25:35,847 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB1CCAA59FEF4C2282B4773D4CF5775B, mem on close (mb), free: 67, total: 318, max: 672
2016-05-18 00:25:38,639 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:38,639 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:38,651 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F754B710BC3945B094C460742F932226, ordinal: 1
2016-05-18 00:25:38,653 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 00:25:38,653 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][3184130251/euclidean/]
2016-05-18 00:25:38,654 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F754B710BC3945B094C460742F932226, mem on start (mb), free: 65, total: 318, max: 672
2016-05-18 00:25:38,684 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F754B710BC3945B094C460742F932226, mem on close (mb), free: 64, total: 318, max: 672
2016-05-18 00:25:41,641 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (3/3) ...osite/euclidean/composite
2016-05-18 00:25:41,699 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0003
2016-05-18 00:25:41,717 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:25:41,725 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3184130251_euclidean_F4B1F073A5FD4FF682B5FC06863A3AF0/part-00000
2016-05-18 00:25:41,825 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:41,825 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:41,838 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CE5A284E05B444EF8CAF34B26D55AE6D, ordinal: 0
2016-05-18 00:25:41,838 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][3184130251/euclidean/]
2016-05-18 00:25:41,839 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2016-05-18 00:25:41,839 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE5A284E05B444EF8CAF34B26D55AE6D, mem on start (mb), free: 112, total: 412, max: 672
2016-05-18 00:25:41,862 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE5A284E05B444EF8CAF34B26D55AE6D, mem on close (mb), free: 112, total: 412, max: 672
2016-05-18 00:25:44,727 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:44,728 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:44,738 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CB9B9548B68B40A9BBE5470A399DBBAB, ordinal: 1
2016-05-18 00:25:44,739 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2016-05-18 00:25:44,740 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite"]
2016-05-18 00:25:44,740 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CB9B9548B68B40A9BBE5470A399DBBAB, mem on start (mb), free: 111, total: 412, max: 672
2016-05-18 00:25:44,757 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CB9B9548B68B40A9BBE5470A399DBBAB, mem on close (mb), free: 110, total: 412, max: 672
2016-05-18 00:25:47,733 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite/_temporary
2016-05-18 00:25:47,735 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] completed in: 00:18.550
2016-05-18 00:25:47,772 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite
2016-05-18 00:25:47,794 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:25:47,794 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 00:25:47,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.132
2016-05-18 00:25:47,935 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 00:25:47,935 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:25:47,999 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting
2016-05-18 00:25:47,999 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:25:47,999 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite"]
2016-05-18 00:25:48,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] parallel execution of steps is enabled: false
2016-05-18 00:25:48,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] executing total steps: 3
2016-05-18 00:25:48,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] allocating management threads: 1
2016-05-18 00:25:48,001 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting step: (1/3)
2016-05-18 00:25:48,060 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] submitted hadoop job: job_local_0004
2016-05-18 00:25:48,061 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] tracking url: http://localhost:8080/
2016-05-18 00:25:48,066 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt
2016-05-18 00:25:48,191 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:48,192 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:48,205 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AA35DDD87FB5496BA28E57D0275E7012, ordinal: 0
2016-05-18 00:25:48,207 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:25:48,207 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 00:25:48,207 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA35DDD87FB5496BA28E57D0275E7012, mem on start (mb), free: 89, total: 508, max: 672
2016-05-18 00:25:48,213 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA35DDD87FB5496BA28E57D0275E7012, mem on close (mb), free: 89, total: 508, max: 672
2016-05-18 00:25:51,070 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:51,070 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:51,081 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AF07945063C14339881E3DBF52ABECC2, ordinal: 1
2016-05-18 00:25:51,082 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 00:25:51,082 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][9891665774/pearson/]
2016-05-18 00:25:51,082 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AF07945063C14339881E3DBF52ABECC2, mem on start (mb), free: 88, total: 508, max: 672
2016-05-18 00:25:51,087 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:25:51,087 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:25:51,119 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AF07945063C14339881E3DBF52ABECC2, mem on close (mb), free: 88, total: 508, max: 672
2016-05-18 00:25:54,074 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting step: (2/3)
2016-05-18 00:25:54,114 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] submitted hadoop job: job_local_0005
2016-05-18 00:25:54,114 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] tracking url: http://localhost:8080/
2016-05-18 00:25:54,120 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/9891665774_pearson_008CE4A8DC8E4CFFBA4ED48404DFB194/part-00000
2016-05-18 00:25:54,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:25:54,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:25:54,224 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A52DD36F52534BCE872C9CE95C86DB3F, ordinal: 0
2016-05-18 00:25:54,225 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][9891665774/pearson/]
2016-05-18 00:25:54,225 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2016-05-18 00:25:54,225 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A52DD36F52534BCE872C9CE95C86DB3F, mem on start (mb), free: 46, total: 570, max: 672
2016-05-18 00:25:54,239 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A52DD36F52534BCE872C9CE95C86DB3F, mem on close (mb), free: 46, total: 570, max: 672
2016-05-18 00:25:57,124 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:25:57,125 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:25:57,136 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A91563D18FEC4916B8698B60B6A37CE1, ordinal: 1
2016-05-18 00:25:57,137 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2016-05-18 00:25:57,137 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6126540187/pearson/]
2016-05-18 00:25:57,137 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A91563D18FEC4916B8698B60B6A37CE1, mem on start (mb), free: 44, total: 570, max: 672
2016-05-18 00:25:57,155 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A91563D18FEC4916B8698B60B6A37CE1, mem on close (mb), free: 44, total: 570, max: 672
2016-05-18 00:26:00,128 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting step: (3/3) ...mposite/pearson/composite
2016-05-18 00:26:00,201 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] submitted hadoop job: job_local_0006
2016-05-18 00:26:00,203 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] tracking url: http://localhost:8080/
2016-05-18 00:26:00,209 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6126540187_pearson_E924D3BF8A7142539D77DA02EFDB8835/part-00000
2016-05-18 00:26:00,480 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:00,481 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:00,494 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E055BD74D5EE4BFABC6BD0496468D148, ordinal: 0
2016-05-18 00:26:00,495 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6126540187/pearson/]
2016-05-18 00:26:00,495 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2016-05-18 00:26:00,495 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E055BD74D5EE4BFABC6BD0496468D148, mem on start (mb), free: 93, total: 201, max: 672
2016-05-18 00:26:00,504 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E055BD74D5EE4BFABC6BD0496468D148, mem on close (mb), free: 93, total: 201, max: 672
2016-05-18 00:26:03,214 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:03,214 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:03,224 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F1D7481B86C94A21B159CC3B8FEC34AB, ordinal: 1
2016-05-18 00:26:03,225 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2016-05-18 00:26:03,225 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite"]
2016-05-18 00:26:03,226 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F1D7481B86C94A21B159CC3B8FEC34AB, mem on start (mb), free: 92, total: 201, max: 672
2016-05-18 00:26:03,240 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F1D7481B86C94A21B159CC3B8FEC34AB, mem on close (mb), free: 91, total: 201, max: 672
2016-05-18 00:26:06,224 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite/_temporary
2016-05-18 00:26:06,226 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] completed in: 00:18.224
2016-05-18 00:26:06,248 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite
2016-05-18 00:26:06,269 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:26:06,269 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 00:26:06,390 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.117
2016-05-18 00:26:06,392 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 00:26:06,393 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:26:06,474 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting
2016-05-18 00:26:06,475 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:26:06,475 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long"]
2016-05-18 00:26:06,476 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] parallel execution of steps is enabled: false
2016-05-18 00:26:06,476 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executing total steps: 3
2016-05-18 00:26:06,477 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] allocating management threads: 1
2016-05-18 00:26:06,479 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (1/3)
2016-05-18 00:26:06,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0007
2016-05-18 00:26:06,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:26:06,518 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt
2016-05-18 00:26:06,536 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:06,536 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:06,547 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A1F0268464CD485986B1C7E28551DB1A, ordinal: 0
2016-05-18 00:26:06,549 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:26:06,549 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 00:26:06,550 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A1F0268464CD485986B1C7E28551DB1A, mem on start (mb), free: 82, total: 205, max: 672
2016-05-18 00:26:06,555 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A1F0268464CD485986B1C7E28551DB1A, mem on close (mb), free: 82, total: 205, max: 672
2016-05-18 00:26:09,529 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:09,529 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:09,536 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CB023EECAF354082BAF8E89604227967, ordinal: 1
2016-05-18 00:26:09,536 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 00:26:09,537 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][8555334919/euclidean/]
2016-05-18 00:26:09,537 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CB023EECAF354082BAF8E89604227967, mem on start (mb), free: 300, total: 314, max: 672
2016-05-18 00:26:09,540 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:26:09,540 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:26:09,559 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CB023EECAF354082BAF8E89604227967, mem on close (mb), free: 299, total: 314, max: 672
2016-05-18 00:26:12,525 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (2/3)
2016-05-18 00:26:12,557 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0008
2016-05-18 00:26:12,562 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:26:12,566 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8555334919_euclidean_E537E01555874BFDB1D9C120FC269116/part-00000
2016-05-18 00:26:12,581 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:12,581 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:12,588 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E552D4A24BE24BF88D68C336B0A2B061, ordinal: 0
2016-05-18 00:26:12,588 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][8555334919/euclidean/]
2016-05-18 00:26:12,588 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 00:26:12,589 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E552D4A24BE24BF88D68C336B0A2B061, mem on start (mb), free: 195, total: 314, max: 672
2016-05-18 00:26:12,598 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E552D4A24BE24BF88D68C336B0A2B061, mem on close (mb), free: 195, total: 314, max: 672
2016-05-18 00:26:15,571 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:15,571 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:15,579 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E234183BAB4440498BA2A3311CDC4B4C, ordinal: 1
2016-05-18 00:26:15,580 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 00:26:15,580 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][1857238909/euclidean/]
2016-05-18 00:26:15,580 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E234183BAB4440498BA2A3311CDC4B4C, mem on start (mb), free: 192, total: 314, max: 672
2016-05-18 00:26:15,599 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E234183BAB4440498BA2A3311CDC4B4C, mem on close (mb), free: 191, total: 314, max: 672
2016-05-18 00:26:18,573 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (3/3) ...anDistance/euclidean/long
2016-05-18 00:26:18,611 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0009
2016-05-18 00:26:18,612 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:26:18,618 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/1857238909_euclidean_B0387D4747C343D582DF378742603555/part-00000
2016-05-18 00:26:18,718 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:18,718 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:18,725 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C548A13863A9405DBF1CD8A69CBC0671, ordinal: 0
2016-05-18 00:26:18,726 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][1857238909/euclidean/]
2016-05-18 00:26:18,726 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 00:26:18,726 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C548A13863A9405DBF1CD8A69CBC0671, mem on start (mb), free: 86, total: 314, max: 672
2016-05-18 00:26:18,734 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C548A13863A9405DBF1CD8A69CBC0671, mem on close (mb), free: 86, total: 314, max: 672
2016-05-18 00:26:21,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:21,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:21,630 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C4F8A354FBD448FAA260AAF83BFB31AD, ordinal: 1
2016-05-18 00:26:21,630 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 00:26:21,631 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long"]
2016-05-18 00:26:21,631 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C4F8A354FBD448FAA260AAF83BFB31AD, mem on start (mb), free: 84, total: 314, max: 672
2016-05-18 00:26:21,641 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C4F8A354FBD448FAA260AAF83BFB31AD, mem on close (mb), free: 83, total: 314, max: 672
2016-05-18 00:26:24,633 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long/_temporary
2016-05-18 00:26:24,634 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] completed in: 00:18.158
2016-05-18 00:26:24,661 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long
2016-05-18 00:26:24,674 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:26:24,674 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 00:26:24,760 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.082
2016-05-18 00:26:24,762 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 00:26:24,762 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:26:24,821 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting
2016-05-18 00:26:24,821 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:26:24,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short"]
2016-05-18 00:26:24,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] parallel execution of steps is enabled: false
2016-05-18 00:26:24,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executing total steps: 3
2016-05-18 00:26:24,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] allocating management threads: 1
2016-05-18 00:26:24,823 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (1/3)
2016-05-18 00:26:24,856 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0010
2016-05-18 00:26:24,857 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:26:24,860 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt
2016-05-18 00:26:24,874 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:24,875 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:24,883 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C80CA154F30F44BFB83800E4395DA777, ordinal: 0
2016-05-18 00:26:24,885 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/critics.txt"]
2016-05-18 00:26:24,885 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 00:26:24,885 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C80CA154F30F44BFB83800E4395DA777, mem on start (mb), free: 188, total: 314, max: 672
2016-05-18 00:26:24,889 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C80CA154F30F44BFB83800E4395DA777, mem on close (mb), free: 188, total: 314, max: 672
2016-05-18 00:26:27,864 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:27,865 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:27,871 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B75C2BD1D16645478CBFDA8C6F4DFDFA, ordinal: 1
2016-05-18 00:26:27,872 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 00:26:27,872 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][1423803635/euclidean/]
2016-05-18 00:26:27,872 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B75C2BD1D16645478CBFDA8C6F4DFDFA, mem on start (mb), free: 186, total: 314, max: 672
2016-05-18 00:26:27,876 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:26:27,876 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 00:26:27,895 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B75C2BD1D16645478CBFDA8C6F4DFDFA, mem on close (mb), free: 185, total: 314, max: 672
2016-05-18 00:26:30,869 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (2/3)
2016-05-18 00:26:30,895 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0011
2016-05-18 00:26:30,896 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:26:30,899 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/1423803635_euclidean_F14FD5F29E9F4EB393C874D3600B7257/part-00000
2016-05-18 00:26:30,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:30,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:30,973 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D8CA7FFAE2E3470EBE11D259B9BF3639, ordinal: 0
2016-05-18 00:26:30,973 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][1423803635/euclidean/]
2016-05-18 00:26:30,973 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 00:26:30,973 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D8CA7FFAE2E3470EBE11D259B9BF3639, mem on start (mb), free: 308, total: 422, max: 672
2016-05-18 00:26:30,983 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D8CA7FFAE2E3470EBE11D259B9BF3639, mem on close (mb), free: 308, total: 422, max: 672
2016-05-18 00:26:33,903 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:33,904 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:33,910 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C1E5578C071044AD9CA80585246EF25F, ordinal: 1
2016-05-18 00:26:33,911 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 00:26:33,911 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8398507657/euclidean/]
2016-05-18 00:26:33,911 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C1E5578C071044AD9CA80585246EF25F, mem on start (mb), free: 305, total: 422, max: 672
2016-05-18 00:26:33,928 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C1E5578C071044AD9CA80585246EF25F, mem on close (mb), free: 305, total: 422, max: 672
2016-05-18 00:26:36,911 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (3/3) ...anceShort/euclidean/short
2016-05-18 00:26:36,939 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0012
2016-05-18 00:26:36,940 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 00:26:36,944 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8398507657_euclidean_32BDE1A18F70449B8101C939A7037806/part-00000
2016-05-18 00:26:36,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:26:36,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:26:36,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E5323774DB6748C7958710D48003A734, ordinal: 0
2016-05-18 00:26:36,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][8398507657/euclidean/]
2016-05-18 00:26:36,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 00:26:36,967 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E5323774DB6748C7958710D48003A734, mem on start (mb), free: 201, total: 422, max: 672
2016-05-18 00:26:36,974 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E5323774DB6748C7958710D48003A734, mem on close (mb), free: 200, total: 422, max: 672
2016-05-18 00:26:39,948 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 00:26:39,948 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 00:26:39,955 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DD3F0869DF53498EB84F2549B99C7918, ordinal: 1
2016-05-18 00:26:39,955 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 00:26:39,955 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short"]
2016-05-18 00:26:39,956 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD3F0869DF53498EB84F2549B99C7918, mem on start (mb), free: 198, total: 422, max: 672
2016-05-18 00:26:39,965 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD3F0869DF53498EB84F2549B99C7918, mem on close (mb), free: 197, total: 422, max: 672
2016-05-18 00:26:42,960 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short/_temporary
2016-05-18 00:26:42,961 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] completed in: 00:18.138
2016-05-18 00:26:42,984 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short