2016-05-18 01:33:24,581 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 01:33:24,605 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.UnmodifiablePipesPlatformTest, with platform: hadoop
2016-05-18 01:33:24,636 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 01:33:24,875 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 01:33:24,985 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:33:24,987 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 01:33:25,104 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: ABFC53B9C111417FAC52AB5172B06E1A
2016-05-18 01:33:25,378 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.230
2016-05-18 01:33:25,382 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 01:33:25,383 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:33:25,611 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 01:33:25,613 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:33:25,614 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['lhs', 'rhs']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:25,614 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/unmodifiablepipesplatform/testUnmodifiable/simple"]
2016-05-18 01:33:25,615 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:33:25,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 2
2016-05-18 01:33:25,617 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:33:25,619 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/2)
2016-05-18 01:33:25,665 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 01:33:25,705 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 01:33:25,926 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0001
2016-05-18 01:33:25,927 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:33:25,992 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/lhs.txt
2016-05-18 01:33:26,135 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:33:26,135 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:33:26,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DCAD599569F145F29B821E1DB6009715, ordinal: 0
2016-05-18 01:33:26,186 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['lhs', 'rhs']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:26,186 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'lhs']]
2016-05-18 01:33:26,187 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DCAD599569F145F29B821E1DB6009715, mem on start (mb), free: 84, total: 223, max: 672
2016-05-18 01:33:26,202 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DCAD599569F145F29B821E1DB6009715, mem on close (mb), free: 84, total: 223, max: 672
2016-05-18 01:33:28,985 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:33:28,985 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:33:29,004 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D31B49AFDF414BDEBFBD5A09FCE6FC5B, ordinal: 1
2016-05-18 01:33:29,009 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'lhs']]
2016-05-18 01:33:29,009 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['lhs', 'rhs']]"][4817721478/test/]
2016-05-18 01:33:29,009 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D31B49AFDF414BDEBFBD5A09FCE6FC5B, mem on start (mb), free: 82, total: 223, max: 672
2016-05-18 01:33:29,032 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D31B49AFDF414BDEBFBD5A09FCE6FC5B, mem on close (mb), free: 81, total: 223, max: 672
2016-05-18 01:33:31,984 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (2/2) ...m/testUnmodifiable/simple
2016-05-18 01:33:32,068 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0002
2016-05-18 01:33:32,069 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:33:32,074 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4817721478_test_3BB883BE4AB84116BC00B371D987E3F5/part-00000
2016-05-18 01:33:32,179 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:33:32,179 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:33:32,190 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C2ECC913844B4F6D95575167D8C07EE7, ordinal: 0
2016-05-18 01:33:32,191 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['lhs', 'rhs']]"][4817721478/test/]
2016-05-18 01:33:32,192 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'lhs']]
2016-05-18 01:33:32,192 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C2ECC913844B4F6D95575167D8C07EE7, mem on start (mb), free: 71, total: 318, max: 672
2016-05-18 01:33:32,194 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C2ECC913844B4F6D95575167D8C07EE7, mem on close (mb), free: 71, total: 318, max: 672
2016-05-18 01:33:35,079 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:33:35,079 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:33:35,092 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F3FFDF8F496B49E9B6FA473AAD1E91E9, ordinal: 1
2016-05-18 01:33:35,094 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'lhs']]
2016-05-18 01:33:35,094 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/unmodifiablepipesplatform/testUnmodifiable/simple"]
2016-05-18 01:33:35,094 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F3FFDF8F496B49E9B6FA473AAD1E91E9, mem on start (mb), free: 69, total: 318, max: 672
2016-05-18 01:33:35,101 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F3FFDF8F496B49E9B6FA473AAD1E91E9, mem on close (mb), free: 69, total: 318, max: 672
2016-05-18 01:33:38,084 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/unmodifiablepipesplatform/testUnmodifiable/simple/_temporary
2016-05-18 01:33:38,086 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:12.470
2016-05-18 01:33:38,103 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/unmodifiablepipesplatform/testUnmodifiable/simple