2016-05-17 22:01:06,358 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-17 22:01:06,389 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.UnmodifiablePipesPlatformTest, with platform: hadoop2-mr1
2016-05-17 22:01:06,419 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-17 22:01:07,000 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-17 22:01:07,153 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-17 22:01:07,291 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:01:07,293 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-17 22:01:07,403 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: B07C3D58CFED47DC94CB0F373CF6F413
2016-05-17 22:01:07,710 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.242
2016-05-17 22:01:07,714 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-17 22:01:07,714 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-17 22:01:07,927 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-17 22:01:07,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 22:01:07,929 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['lhs', 'rhs']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/lhs.txt"]
2016-05-17 22:01:07,929 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/unmodifiablepipesplatform/testUnmodifiable/simple"]
2016-05-17 22:01:07,930 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-17 22:01:07,931 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 2
2016-05-17 22:01:07,931 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 22:01:07,932 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/2)
2016-05-17 22:01:08,449 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1047057939/.staging/job_local1047057939_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:01:08,462 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1047057939/.staging/job_local1047057939_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:01:08,604 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1047057939_0001/job_local1047057939_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:01:08,606 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1047057939_0001/job_local1047057939_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:01:08,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1047057939_0001
2016-05-17 22:01:08,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 22:01:08,695 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/lhs.txt
2016-05-17 22:01:08,872 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:01:08,872 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:01:08,892 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BB4FBA06A8BB4F47B761E35659E9AB0F, ordinal: 0
2016-05-17 22:01:08,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['lhs', 'rhs']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/lhs.txt"]
2016-05-17 22:01:08,939 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'lhs']]
2016-05-17 22:01:08,940 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB4FBA06A8BB4F47B761E35659E9AB0F, mem on start (mb), free: 147, total: 281, max: 672
2016-05-17 22:01:08,953 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB4FBA06A8BB4F47B761E35659E9AB0F, mem on close (mb), free: 146, total: 281, max: 672
2016-05-17 22:01:09,001 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 22:01:09,001 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 22:01:09,013 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E169E83652FC46588C99262DEC3E5D56, ordinal: 1
2016-05-17 22:01:09,017 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'lhs']]
2016-05-17 22:01:09,017 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[['lhs', 'rhs']]"][487597900/test/]
2016-05-17 22:01:09,017 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E169E83652FC46588C99262DEC3E5D56, mem on start (mb), free: 143, total: 281, max: 672
2016-05-17 22:01:09,049 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E169E83652FC46588C99262DEC3E5D56, mem on close (mb), free: 142, total: 281, max: 672
2016-05-17 22:01:09,109 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (2/2) ...m/testUnmodifiable/simple
2016-05-17 22:01:09,199 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1133450560/.staging/job_local1133450560_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:01:09,203 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1133450560/.staging/job_local1133450560_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:01:09,253 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1133450560_0002/job_local1133450560_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:01:09,253 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1133450560_0002/job_local1133450560_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:01:09,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1133450560_0002
2016-05-17 22:01:09,256 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 22:01:09,263 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/487597900_test_A6BCBA788285495780FF5B2573CA4EE4/part-00000
2016-05-17 22:01:09,376 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:01:09,376 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:01:09,386 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5E588C2FB37419EAC8D3A95641E4DEF, ordinal: 0
2016-05-17 22:01:09,387 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[['lhs', 'rhs']]"][487597900/test/]
2016-05-17 22:01:09,387 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'lhs']]
2016-05-17 22:01:09,388 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5E588C2FB37419EAC8D3A95641E4DEF, mem on start (mb), free: 108, total: 382, max: 672
2016-05-17 22:01:09,391 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5E588C2FB37419EAC8D3A95641E4DEF, mem on close (mb), free: 108, total: 382, max: 672
2016-05-17 22:01:09,407 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 22:01:09,407 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 22:01:09,420 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E57C08CA5CE146F89956A5A1EB81FB34, ordinal: 1
2016-05-17 22:01:09,422 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'lhs']]
2016-05-17 22:01:09,422 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/unmodifiablepipesplatform/testUnmodifiable/simple"]
2016-05-17 22:01:09,422 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E57C08CA5CE146F89956A5A1EB81FB34, mem on start (mb), free: 107, total: 382, max: 672
2016-05-17 22:01:09,434 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E57C08CA5CE146F89956A5A1EB81FB34, mem on close (mb), free: 106, total: 382, max: 672
2016-05-17 22:01:09,458 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/unmodifiablepipesplatform/testUnmodifiable/simple/_temporary
2016-05-17 22:01:09,458 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:01.528
2016-05-17 22:01:09,505 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/unmodifiablepipesplatform/testUnmodifiable/simple