2016-05-18 03:13:20,788 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 03:13:20,804 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.DistanceUseCasePlatformTest, with platform: hadoop
2016-05-18 03:13:20,829 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 03:13:21,076 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 03:13:21,191 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:13:21,194 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 03:13:21,308 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 223EA7F56C4E40C88E3F18B1E0758E23
2016-05-18 03:13:21,622 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.270
2016-05-18 03:13:21,627 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 03:13:21,627 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 03:13:21,878 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 03:13:21,880 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting
2016-05-18 03:13:21,880 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:21,881 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite"]
2016-05-18 03:13:21,881 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] parallel execution of steps is enabled: false
2016-05-18 03:13:21,881 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executing total steps: 3
2016-05-18 03:13:21,881 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] allocating management threads: 1
2016-05-18 03:13:21,882 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (1/3)
2016-05-18 03:13:21,918 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 03:13:21,964 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 03:13:22,190 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0001
2016-05-18 03:13:22,191 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:22,263 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/critics.txt
2016-05-18 03:13:22,476 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:22,477 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:22,507 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A38E01DDD02545359D2D5D189F271AAE, ordinal: 0
2016-05-18 03:13:22,563 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:22,563 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 03:13:22,565 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A38E01DDD02545359D2D5D189F271AAE, mem on start (mb), free: 76, total: 223, max: 672
2016-05-18 03:13:22,587 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A38E01DDD02545359D2D5D189F271AAE, mem on close (mb), free: 76, total: 223, max: 672
2016-05-18 03:13:22,623 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:22,624 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:22,642 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D316DF7AE000404CB9FCE7CF26CC18B3, ordinal: 1
2016-05-18 03:13:22,646 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 03:13:22,647 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6059933500/euclidean/]
2016-05-18 03:13:22,647 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D316DF7AE000404CB9FCE7CF26CC18B3, mem on start (mb), free: 74, total: 223, max: 672
2016-05-18 03:13:22,669 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:22,670 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:22,711 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D316DF7AE000404CB9FCE7CF26CC18B3, mem on close (mb), free: 72, total: 223, max: 672
2016-05-18 03:13:22,727 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (2/3)
2016-05-18 03:13:22,814 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0002
2016-05-18 03:13:22,814 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:22,820 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6059933500_euclidean_0AD20B88DD8140878B552F070FB1DE91/part-00000
2016-05-18 03:13:22,945 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:22,945 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:22,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D2B5855C88F04F0C81B5335FD1448007, ordinal: 0
2016-05-18 03:13:22,960 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][6059933500/euclidean/]
2016-05-18 03:13:22,961 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 03:13:22,961 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2B5855C88F04F0C81B5335FD1448007, mem on start (mb), free: 172, total: 377, max: 672
2016-05-18 03:13:23,004 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2B5855C88F04F0C81B5335FD1448007, mem on close (mb), free: 171, total: 377, max: 672
2016-05-18 03:13:23,050 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:23,050 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:23,062 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D0F41725916344C3AC565106DFF2259F, ordinal: 1
2016-05-18 03:13:23,064 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 03:13:23,065 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][8501622794/euclidean/]
2016-05-18 03:13:23,065 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D0F41725916344C3AC565106DFF2259F, mem on start (mb), free: 169, total: 377, max: 672
2016-05-18 03:13:23,092 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D0F41725916344C3AC565106DFF2259F, mem on close (mb), free: 168, total: 377, max: 672
2016-05-18 03:13:23,108 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (3/3) ...osite/euclidean/composite
2016-05-18 03:13:23,166 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0003
2016-05-18 03:13:23,166 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:23,171 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8501622794_euclidean_9C02C588FFF84B64B5012755BE856C60/part-00000
2016-05-18 03:13:23,229 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:23,230 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:23,242 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D4424EE28E3642B5BB415D348AF8A184, ordinal: 0
2016-05-18 03:13:23,243 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][8501622794/euclidean/]
2016-05-18 03:13:23,243 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2016-05-18 03:13:23,244 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D4424EE28E3642B5BB415D348AF8A184, mem on start (mb), free: 63, total: 377, max: 672
2016-05-18 03:13:23,261 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D4424EE28E3642B5BB415D348AF8A184, mem on close (mb), free: 62, total: 377, max: 672
2016-05-18 03:13:23,281 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:23,282 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:23,294 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DDA2A95AA3D94B6F97CA19BC3B5B36E4, ordinal: 1
2016-05-18 03:13:23,295 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'n1', 'n2']]
2016-05-18 03:13:23,296 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite"]
2016-05-18 03:13:23,296 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DDA2A95AA3D94B6F97CA19BC3B5B36E4, mem on start (mb), free: 61, total: 377, max: 672
2016-05-18 03:13:23,313 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DDA2A95AA3D94B6F97CA19BC3B5B36E4, mem on close (mb), free: 60, total: 377, max: 672
2016-05-18 03:13:23,342 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite/_temporary
2016-05-18 03:13:23,344 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] completed in: 00:01.449
2016-05-18 03:13:23,384 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistanceComposite/euclidean/composite
2016-05-18 03:13:23,412 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:13:23,413 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 03:13:23,607 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.188
2016-05-18 03:13:23,611 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 03:13:23,612 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 03:13:23,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting
2016-05-18 03:13:23,721 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:23,722 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite"]
2016-05-18 03:13:23,723 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] parallel execution of steps is enabled: false
2016-05-18 03:13:23,724 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] executing total steps: 3
2016-05-18 03:13:23,724 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] allocating management threads: 1
2016-05-18 03:13:23,725 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting step: (1/3)
2016-05-18 03:13:23,776 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] submitted hadoop job: job_local_0004
2016-05-18 03:13:23,777 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] tracking url: http://localhost:8080/
2016-05-18 03:13:23,780 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/critics.txt
2016-05-18 03:13:24,021 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:24,022 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,032 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B55936954E0F4A38934180F2201B1D0D, ordinal: 0
2016-05-18 03:13:24,033 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:24,034 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 03:13:24,034 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B55936954E0F4A38934180F2201B1D0D, mem on start (mb), free: 404, total: 512, max: 672
2016-05-18 03:13:24,038 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B55936954E0F4A38934180F2201B1D0D, mem on close (mb), free: 404, total: 512, max: 672
2016-05-18 03:13:24,048 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:24,048 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,058 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D2948277BCA84C9199ACF952BC3F68B1, ordinal: 1
2016-05-18 03:13:24,059 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(pearson)[by:[{1}:'l'][numSelfJoins:1]]
2016-05-18 03:13:24,059 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][4864137150/pearson/]
2016-05-18 03:13:24,059 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D2948277BCA84C9199ACF952BC3F68B1, mem on start (mb), free: 401, total: 512, max: 672
2016-05-18 03:13:24,063 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:24,064 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:24,088 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D2948277BCA84C9199ACF952BC3F68B1, mem on close (mb), free: 400, total: 512, max: 672
2016-05-18 03:13:24,101 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting step: (2/3)
2016-05-18 03:13:24,135 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] submitted hadoop job: job_local_0005
2016-05-18 03:13:24,135 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] tracking url: http://localhost:8080/
2016-05-18 03:13:24,139 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4864137150_pearson_35782AAF5ADA4664B8274B348C444B89/part-00000
2016-05-18 03:13:24,154 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:24,155 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,163 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CCF64F4EB6764FF2AB22DB6D2D1A1CD4, ordinal: 0
2016-05-18 03:13:24,164 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][4864137150/pearson/]
2016-05-18 03:13:24,164 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pearson)[by:[{?}:ALL]]
2016-05-18 03:13:24,164 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CCF64F4EB6764FF2AB22DB6D2D1A1CD4, mem on start (mb), free: 294, total: 512, max: 672
2016-05-18 03:13:24,178 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CCF64F4EB6764FF2AB22DB6D2D1A1CD4, mem on close (mb), free: 294, total: 512, max: 672
2016-05-18 03:13:24,198 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:24,198 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,207 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F3D63F595D3B4D75A5485897998E31EB, ordinal: 1
2016-05-18 03:13:24,207 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pearson)[by:[{?}:ALL]]
2016-05-18 03:13:24,208 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][2852122444/pearson/]
2016-05-18 03:13:24,208 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F3D63F595D3B4D75A5485897998E31EB, mem on start (mb), free: 291, total: 512, max: 672
2016-05-18 03:13:24,225 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F3D63F595D3B4D75A5485897998E31EB, mem on close (mb), free: 291, total: 512, max: 672
2016-05-18 03:13:24,237 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] starting step: (3/3) ...mposite/pearson/composite
2016-05-18 03:13:24,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] submitted hadoop job: job_local_0006
2016-05-18 03:13:24,272 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] tracking url: http://localhost:8080/
2016-05-18 03:13:24,276 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/2852122444_pearson_5133303109AD416F8AFD85CF1FD6BEDC/part-00000
2016-05-18 03:13:24,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:24,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,373 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CC3A4BD7F6254075BAF2FE9C4979FDD7, ordinal: 0
2016-05-18 03:13:24,373 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['l', 'n1', 'v1', 'n2', 'v2']]"][2852122444/pearson/]
2016-05-18 03:13:24,374 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2016-05-18 03:13:24,374 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC3A4BD7F6254075BAF2FE9C4979FDD7, mem on start (mb), free: 185, total: 512, max: 672
2016-05-18 03:13:24,380 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC3A4BD7F6254075BAF2FE9C4979FDD7, mem on close (mb), free: 185, total: 512, max: 672
2016-05-18 03:13:24,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:24,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,400 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A447473FC3A5414CB9077AFFC7841AF4, ordinal: 1
2016-05-18 03:13:24,401 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pearson)[by:[{2}:'n1', 'n2']]
2016-05-18 03:13:24,402 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite"]
2016-05-18 03:13:24,402 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A447473FC3A5414CB9077AFFC7841AF4, mem on start (mb), free: 183, total: 512, max: 672
2016-05-18 03:13:24,415 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A447473FC3A5414CB9077AFFC7841AF4, mem on close (mb), free: 181, total: 512, max: 672
2016-05-18 03:13:24,425 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite/_temporary
2016-05-18 03:13:24,426 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pearson] completed in: 00:00.704
2016-05-18 03:13:24,448 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testPearsonDistanceComposite/pearson/composite
2016-05-18 03:13:24,476 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:13:24,476 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 03:13:24,573 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.092
2016-05-18 03:13:24,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 03:13:24,575 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 03:13:24,626 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting
2016-05-18 03:13:24,627 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:24,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long"]
2016-05-18 03:13:24,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] parallel execution of steps is enabled: false
2016-05-18 03:13:24,629 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executing total steps: 3
2016-05-18 03:13:24,629 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] allocating management threads: 1
2016-05-18 03:13:24,631 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (1/3)
2016-05-18 03:13:24,677 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0007
2016-05-18 03:13:24,677 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:24,684 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/critics.txt
2016-05-18 03:13:24,701 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:24,701 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,714 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BB3FC89D7408432995C9A467B7167CA5, ordinal: 0
2016-05-18 03:13:24,716 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:24,716 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 03:13:24,717 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB3FC89D7408432995C9A467B7167CA5, mem on start (mb), free: 283, total: 507, max: 672
2016-05-18 03:13:24,733 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB3FC89D7408432995C9A467B7167CA5, mem on close (mb), free: 283, total: 507, max: 672
2016-05-18 03:13:24,748 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:24,749 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,762 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F0988D0E9D124970B382EEE314056798, ordinal: 1
2016-05-18 03:13:24,763 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 03:13:24,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][6452136113/euclidean/]
2016-05-18 03:13:24,764 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F0988D0E9D124970B382EEE314056798, mem on start (mb), free: 281, total: 507, max: 672
2016-05-18 03:13:24,769 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:24,769 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:24,798 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F0988D0E9D124970B382EEE314056798, mem on close (mb), free: 280, total: 507, max: 672
2016-05-18 03:13:24,811 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (2/3)
2016-05-18 03:13:24,859 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0008
2016-05-18 03:13:24,861 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:24,867 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6452136113_euclidean_E53BBF007C2A4944B59FE399F1103C3C/part-00000
2016-05-18 03:13:24,885 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:24,886 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,896 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D1B9189275224B26BAE91BE980E1C177, ordinal: 0
2016-05-18 03:13:24,897 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][6452136113/euclidean/]
2016-05-18 03:13:24,897 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 03:13:24,897 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1B9189275224B26BAE91BE980E1C177, mem on start (mb), free: 174, total: 507, max: 672
2016-05-18 03:13:24,910 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1B9189275224B26BAE91BE980E1C177, mem on close (mb), free: 174, total: 507, max: 672
2016-05-18 03:13:24,933 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:24,933 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:24,944 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C65924399D544B9DB7DE0069621461AE, ordinal: 1
2016-05-18 03:13:24,945 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 03:13:24,945 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][2315656200/euclidean/]
2016-05-18 03:13:24,945 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C65924399D544B9DB7DE0069621461AE, mem on start (mb), free: 170, total: 507, max: 672
2016-05-18 03:13:24,972 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C65924399D544B9DB7DE0069621461AE, mem on close (mb), free: 169, total: 507, max: 672
2016-05-18 03:13:24,984 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (3/3) ...anDistance/euclidean/long
2016-05-18 03:13:25,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0009
2016-05-18 03:13:25,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:25,045 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/2315656200_euclidean_B4F3FF8EA43A434787CFBA817FB333DE/part-00000
2016-05-18 03:13:25,059 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:25,060 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,065 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C472EE990AD54193ABA79C7303603C15, ordinal: 0
2016-05-18 03:13:25,066 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][2315656200/euclidean/]
2016-05-18 03:13:25,066 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 03:13:25,067 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C472EE990AD54193ABA79C7303603C15, mem on start (mb), free: 298, total: 511, max: 672
2016-05-18 03:13:25,072 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C472EE990AD54193ABA79C7303603C15, mem on close (mb), free: 298, total: 511, max: 672
2016-05-18 03:13:25,082 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:25,082 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,089 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F688FCB376054E17BCC1E759351F531B, ordinal: 1
2016-05-18 03:13:25,090 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 03:13:25,090 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long"]
2016-05-18 03:13:25,091 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F688FCB376054E17BCC1E759351F531B, mem on start (mb), free: 296, total: 511, max: 672
2016-05-18 03:13:25,103 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F688FCB376054E17BCC1E759351F531B, mem on close (mb), free: 295, total: 511, max: 672
2016-05-18 03:13:25,114 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long/_temporary
2016-05-18 03:13:25,115 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] completed in: 00:00.487
2016-05-18 03:13:25,132 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistance/euclidean/long
2016-05-18 03:13:25,143 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:13:25,144 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 03:13:25,239 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.089
2016-05-18 03:13:25,240 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 3, nodes: 6
2016-05-18 03:13:25,240 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 03:13:25,291 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting
2016-05-18 03:13:25,291 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:25,291 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short"]
2016-05-18 03:13:25,291 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] parallel execution of steps is enabled: false
2016-05-18 03:13:25,292 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] executing total steps: 3
2016-05-18 03:13:25,292 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] allocating management threads: 1
2016-05-18 03:13:25,292 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (1/3)
2016-05-18 03:13:25,317 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0010
2016-05-18 03:13:25,319 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:25,321 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/critics.txt
2016-05-18 03:13:25,335 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:25,336 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,341 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FF056836BE6B4CB297E77DCB0F1DA574, ordinal: 0
2016-05-18 03:13:25,342 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.1.x/build/classes/test/data/critics.txt"]
2016-05-18 03:13:25,342 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 03:13:25,342 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FF056836BE6B4CB297E77DCB0F1DA574, mem on start (mb), free: 175, total: 511, max: 672
2016-05-18 03:13:25,345 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FF056836BE6B4CB297E77DCB0F1DA574, mem on close (mb), free: 175, total: 511, max: 672
2016-05-18 03:13:25,357 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:25,357 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,362 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: ED66FFB562DD454C8C13353FB48F80A1, ordinal: 1
2016-05-18 03:13:25,363 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(euclidean)[by:[{1}:'movie'][numSelfJoins:1]]
2016-05-18 03:13:25,363 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][7113196646/euclidean/]
2016-05-18 03:13:25,363 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ED66FFB562DD454C8C13353FB48F80A1, mem on start (mb), free: 401, total: 511, max: 672
2016-05-18 03:13:25,366 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:25,366 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:13:25,385 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ED66FFB562DD454C8C13353FB48F80A1, mem on close (mb), free: 401, total: 511, max: 672
2016-05-18 03:13:25,394 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (2/3)
2016-05-18 03:13:25,419 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0011
2016-05-18 03:13:25,419 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:25,424 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/7113196646_euclidean_B02BE381A07346DB8A4B0D74E1850DF7/part-00000
2016-05-18 03:13:25,439 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:25,439 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,446 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FBE8AD6EC9894D89B0928139331D47E8, ordinal: 0
2016-05-18 03:13:25,447 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2']]"][7113196646/euclidean/]
2016-05-18 03:13:25,447 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 03:13:25,447 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FBE8AD6EC9894D89B0928139331D47E8, mem on start (mb), free: 295, total: 511, max: 672
2016-05-18 03:13:25,457 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FBE8AD6EC9894D89B0928139331D47E8, mem on close (mb), free: 294, total: 511, max: 672
2016-05-18 03:13:25,468 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:25,468 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,475 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: ED91691D35A7437F8A0D2C50BC053C55, ordinal: 1
2016-05-18 03:13:25,475 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{?}:ALL]]
2016-05-18 03:13:25,476 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][351496368/euclidean/]
2016-05-18 03:13:25,476 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ED91691D35A7437F8A0D2C50BC053C55, mem on start (mb), free: 292, total: 511, max: 672
2016-05-18 03:13:25,493 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ED91691D35A7437F8A0D2C50BC053C55, mem on close (mb), free: 292, total: 511, max: 672
2016-05-18 03:13:25,502 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] starting step: (3/3) ...anceShort/euclidean/short
2016-05-18 03:13:25,535 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] submitted hadoop job: job_local_0012
2016-05-18 03:13:25,536 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] tracking url: http://localhost:8080/
2016-05-18 03:13:25,542 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/351496368_euclidean_50909C2321BC490C908FC9534D202CB0/part-00000
2016-05-18 03:13:25,558 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:13:25,558 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,568 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F59B21A1C83F4C808BEF891A57DCB2D0, ordinal: 0
2016-05-18 03:13:25,568 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['movie', 'name1', 'rate1', 'name2', 'rate2', 'score']]"][351496368/euclidean/]
2016-05-18 03:13:25,569 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 03:13:25,569 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F59B21A1C83F4C808BEF891A57DCB2D0, mem on start (mb), free: 186, total: 511, max: 672
2016-05-18 03:13:25,576 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F59B21A1C83F4C808BEF891A57DCB2D0, mem on close (mb), free: 185, total: 511, max: 672
2016-05-18 03:13:25,589 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:13:25,590 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:13:25,599 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BADB34A94C794737A2C6E60E71FD81C8, ordinal: 1
2016-05-18 03:13:25,600 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(euclidean)[by:[{2}:'name1', 'name2']]
2016-05-18 03:13:25,600 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short"]
2016-05-18 03:13:25,601 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BADB34A94C794737A2C6E60E71FD81C8, mem on start (mb), free: 183, total: 511, max: 672
2016-05-18 03:13:25,613 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BADB34A94C794737A2C6E60E71FD81C8, mem on close (mb), free: 183, total: 511, max: 672
2016-05-18 03:13:25,630 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short/_temporary
2016-05-18 03:13:25,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [euclidean] completed in: 00:00.338
2016-05-18 03:13:25,656 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/distanceusecaseplatform/testEuclideanDistanceShort/euclidean/short