2016-01-14 17:47:54,666 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 17:47:54,688 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.BasicPipesPlatformTest, with platform: hadoop2-mr1
2016-01-14 17:47:54,719 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-14 17:47:55,334 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 17:47:55,520 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 17:47:55,649 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:47:55,651 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:47:55,773 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 707D7CBCEF0140F4A865C817F6717903
2016-01-14 17:47:56,029 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.187
2016-01-14 17:47:56,033 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 17:47:56,034 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:47:56,243 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 17:47:56,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:47:56,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:47:56,246 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain"]
2016-01-14 17:47:56,246 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:47:56,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 2
2016-01-14 17:47:56,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:47:56,249 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/2)
2016-01-14 17:47:56,811 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity2115302964/.staging/job_local2115302964_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:56,811 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity2115302964/.staging/job_local2115302964_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:57,009 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2115302964_0001/job_local2115302964_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:57,009 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2115302964_0001/job_local2115302964_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:57,022 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local2115302964_0001
2016-01-14 17:47:57,023 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:47:57,131 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:47:57,273 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:57,274 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:57,287 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C440944BEB35468CBA6EFAA976204EE9, ordinal: 0
2016-01-14 17:47:57,333 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:47:57,333 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:47:57,334 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C440944BEB35468CBA6EFAA976204EE9, mem on start (mb), free: 85, total: 223, max: 672
2016-01-14 17:47:57,344 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C440944BEB35468CBA6EFAA976204EE9, mem on close (mb), free: 85, total: 223, max: 672
2016-01-14 17:47:57,469 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:47:57,469 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:47:57,480 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CC3E9424A0394017A266378C9123AA30, ordinal: 1
2016-01-14 17:47:57,484 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:47:57,484 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[0, 'count']]"][9337121869/test/]
2016-01-14 17:47:57,485 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CC3E9424A0394017A266378C9123AA30, mem on start (mb), free: 75, total: 223, max: 672
2016-01-14 17:47:57,512 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CC3E9424A0394017A266378C9123AA30, mem on close (mb), free: 74, total: 223, max: 672
2016-01-14 17:47:57,537 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (2/2) ...stSimpleChain/simplechain
2016-01-14 17:47:57,629 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity172368167/.staging/job_local172368167_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:57,629 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity172368167/.staging/job_local172368167_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:57,704 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local172368167_0002/job_local172368167_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:57,704 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local172368167_0002/job_local172368167_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:57,707 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local172368167_0002
2016-01-14 17:47:57,707 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:47:57,712 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/9337121869_test_27EEEE383FD047D5BADBC0AAC8FAECF0/part-00000
2016-01-14 17:47:57,825 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:57,825 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:57,836 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D24F7A9E2A2947B4A4482FBC50318022, ordinal: 0
2016-01-14 17:47:57,836 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[0, 'count']]"][9337121869/test/]
2016-01-14 17:47:57,837 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:47:57,837 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D24F7A9E2A2947B4A4482FBC50318022, mem on start (mb), free: 103, total: 323, max: 672
2016-01-14 17:47:57,840 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D24F7A9E2A2947B4A4482FBC50318022, mem on close (mb), free: 103, total: 323, max: 672
2016-01-14 17:47:57,859 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:47:57,861 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:47:57,870 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D345D447D6CA422FB22068F3693B9929, ordinal: 1
2016-01-14 17:47:57,871 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:47:57,871 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain"]
2016-01-14 17:47:57,872 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D345D447D6CA422FB22068F3693B9929, mem on start (mb), free: 100, total: 323, max: 672
2016-01-14 17:47:57,884 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D345D447D6CA422FB22068F3693B9929, mem on close (mb), free: 100, total: 323, max: 672
2016-01-14 17:47:57,912 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain/_temporary
2016-01-14 17:47:57,912 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:01.666
2016-01-14 17:47:57,952 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain
2016-01-14 17:47:57,977 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:47:57,977 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:47:58,037 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-01-14 17:47:58,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:47:58,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:47:58,063 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 17:47:58,063 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:47:58,064 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count"]
2016-01-14 17:47:58,065 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 17:47:58,066 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 17:47:58,066 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 17:47:58,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...splatform/testCount/count
2016-01-14 17:47:58,173 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1141026290/.staging/job_local1141026290_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:58,173 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1141026290/.staging/job_local1141026290_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:58,247 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1141026290_0003/job_local1141026290_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:58,247 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1141026290_0003/job_local1141026290_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:58,249 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local1141026290_0003
2016-01-14 17:47:58,249 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 17:47:58,260 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt
2016-01-14 17:47:58,376 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:58,377 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:58,390 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B70DF2C8F16449C5B761BD82F06E60DE, ordinal: 0
2016-01-14 17:47:58,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:47:58,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:47:58,392 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B70DF2C8F16449C5B761BD82F06E60DE, mem on start (mb), free: 59, total: 424, max: 672
2016-01-14 17:47:58,397 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B70DF2C8F16449C5B761BD82F06E60DE, mem on close (mb), free: 59, total: 424, max: 672
2016-01-14 17:47:58,419 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:47:58,419 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:47:58,426 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E91A88B2923844FA9189CDAF7319234F, ordinal: 1
2016-01-14 17:47:58,427 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:47:58,427 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count"]
2016-01-14 17:47:58,427 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E91A88B2923844FA9189CDAF7319234F, mem on start (mb), free: 56, total: 424, max: 672
2016-01-14 17:47:58,443 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E91A88B2923844FA9189CDAF7319234F, mem on close (mb), free: 55, total: 424, max: 672
2016-01-14 17:47:58,491 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count/_temporary
2016-01-14 17:47:58,492 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.426
2016-01-14 17:47:58,558 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount/count
2016-01-14 17:47:58,576 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:47:58,577 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:47:58,620 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.036
2016-01-14 17:47:58,621 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:47:58,621 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:47:58,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:47:58,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:47:58,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSwap/swap"]
2016-01-14 17:47:58,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:47:58,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:47:58,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:47:58,636 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...pesplatform/testSwap/swap
2016-01-14 17:47:58,716 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity638939335/.staging/job_local638939335_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:58,716 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity638939335/.staging/job_local638939335_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:58,764 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local638939335_0004/job_local638939335_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:58,764 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local638939335_0004/job_local638939335_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:58,766 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local638939335_0004
2016-01-14 17:47:58,766 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:47:58,772 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:47:58,781 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:58,781 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:58,788 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E2E250E6CC59445499FE484E52A942E3, ordinal: 0
2016-01-14 17:47:58,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:47:58,790 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSwap/swap"]
2016-01-14 17:47:58,790 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E2E250E6CC59445499FE484E52A942E3, mem on start (mb), free: 125, total: 482, max: 672
2016-01-14 17:47:58,792 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E2E250E6CC59445499FE484E52A942E3, mem on close (mb), free: 125, total: 482, max: 672
2016-01-14 17:47:58,811 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSwap/swap/_temporary
2016-01-14 17:47:58,812 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.176
2016-01-14 17:47:58,838 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSwap/swap
2016-01-14 17:47:58,858 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:47:58,859 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:47:58,900 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-01-14 17:47:58,901 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:47:58,901 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:47:58,916 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:47:58,917 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 17:47:58,917 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped"]
2016-01-14 17:47:58,917 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:47:58,917 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:47:58,918 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:47:58,918 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...orm/testUnGroup/ungrouped
2016-01-14 17:47:58,982 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1203172059/.staging/job_local1203172059_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:58,982 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1203172059/.staging/job_local1203172059_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:59,038 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1203172059_0005/job_local1203172059_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:59,039 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1203172059_0005/job_local1203172059_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:59,040 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1203172059_0005
2016-01-14 17:47:59,041 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:47:59,047 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-01-14 17:47:59,055 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:59,056 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:59,065 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A6E2CB06F17849AB8424263050F75099, ordinal: 0
2016-01-14 17:47:59,066 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 17:47:59,066 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped"]
2016-01-14 17:47:59,066 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A6E2CB06F17849AB8424263050F75099, mem on start (mb), free: 82, total: 482, max: 672
2016-01-14 17:47:59,069 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A6E2CB06F17849AB8424263050F75099, mem on close (mb), free: 82, total: 482, max: 672
2016-01-14 17:47:59,085 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped/_temporary
2016-01-14 17:47:59,085 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.168
2016-01-14 17:47:59,118 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped
2016-01-14 17:47:59,141 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:47:59,141 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:47:59,195 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.049
2016-01-14 17:47:59,196 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:47:59,197 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:47:59,228 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 17:47:59,228 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/upper.txt"]
2016-01-14 17:47:59,229 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:47:59,229 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-01-14 17:47:59,230 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: false
2016-01-14 17:47:59,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 17:47:59,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 17:47:59,232 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...lexcogrouprelativeunknown
2016-01-14 17:47:59,327 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1206911181/.staging/job_local1206911181_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:59,327 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1206911181/.staging/job_local1206911181_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:59,365 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1206911181_0006/job_local1206911181_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:47:59,365 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1206911181_0006/job_local1206911181_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:47:59,366 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted hadoop job: job_local1206911181_0006
2016-01-14 17:47:59,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tracking url: http://localhost:8080/
2016-01-14 17:47:59,373 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/upper.txt
2016-01-14 17:47:59,397 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:59,398 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:59,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A80265C632694404BAE2E2E3FCF26BF8, ordinal: 0
2016-01-14 17:47:59,759 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/upper.txt"]
2016-01-14 17:47:59,759 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-01-14 17:47:59,759 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A80265C632694404BAE2E2E3FCF26BF8, mem on start (mb), free: 435, total: 543, max: 672
2016-01-14 17:47:59,761 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A80265C632694404BAE2E2E3FCF26BF8, mem on close (mb), free: 435, total: 543, max: 672
2016-01-14 17:47:59,771 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt
2016-01-14 17:47:59,785 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:47:59,785 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:47:59,794 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A80265C632694404BAE2E2E3FCF26BF8, ordinal: 0
2016-01-14 17:47:59,795 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:47:59,795 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-01-14 17:47:59,795 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A80265C632694404BAE2E2E3FCF26BF8, mem on start (mb), free: 334, total: 543, max: 672
2016-01-14 17:47:59,797 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A80265C632694404BAE2E2E3FCF26BF8, mem on close (mb), free: 334, total: 543, max: 672
2016-01-14 17:47:59,816 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:47:59,816 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:47:59,823 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B7FA140DE28E47BAA279F5AFFCEEE614, ordinal: 1
2016-01-14 17:47:59,823 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-01-14 17:47:59,824 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-01-14 17:47:59,824 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B7FA140DE28E47BAA279F5AFFCEEE614, mem on start (mb), free: 325, total: 543, max: 672
2016-01-14 17:47:59,837 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 17:47:59,837 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 17:47:59,845 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B7FA140DE28E47BAA279F5AFFCEEE614, mem on close (mb), free: 322, total: 543, max: 672
2016-01-14 17:47:59,871 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown/_temporary
2016-01-14 17:47:59,872 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:00.643
2016-01-14 17:47:59,917 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown
2016-01-14 17:47:59,934 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:47:59,935 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:47:59,979 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-01-14 17:47:59,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:47:59,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:00,008 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:00,008 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:00,009 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-01-14 17:48:00,009 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:00,009 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:00,009 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:00,010 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...leRelative/simplerelative
2016-01-14 17:48:00,081 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1285695819/.staging/job_local1285695819_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:00,081 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1285695819/.staging/job_local1285695819_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:00,133 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1285695819_0007/job_local1285695819_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:00,133 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1285695819_0007/job_local1285695819_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:00,135 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1285695819_0007
2016-01-14 17:48:00,135 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:00,141 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:48:00,162 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:00,162 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:00,170 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F27C489D1D8449D4BFB6CA0EE24E62F1, ordinal: 0
2016-01-14 17:48:00,171 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:00,171 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:48:00,171 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F27C489D1D8449D4BFB6CA0EE24E62F1, mem on start (mb), free: 324, total: 534, max: 672
2016-01-14 17:48:00,173 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F27C489D1D8449D4BFB6CA0EE24E62F1, mem on close (mb), free: 324, total: 534, max: 672
2016-01-14 17:48:00,188 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:00,188 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:00,198 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E7158173489343EBB83CA11F0BD2C4FB, ordinal: 1
2016-01-14 17:48:00,199 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:48:00,199 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-01-14 17:48:00,199 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E7158173489343EBB83CA11F0BD2C4FB, mem on start (mb), free: 317, total: 534, max: 672
2016-01-14 17:48:00,208 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E7158173489343EBB83CA11F0BD2C4FB, mem on close (mb), free: 316, total: 534, max: 672
2016-01-14 17:48:00,228 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative/_temporary
2016-01-14 17:48:00,228 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.219
2016-01-14 17:48:00,254 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative
2016-01-14 17:48:00,376 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:00,376 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:00,427 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.045
2016-01-14 17:48:00,428 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:00,428 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:00,452 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:00,452 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:48:00,452 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult"]
2016-01-14 17:48:00,452 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:00,452 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:00,453 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:00,453 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...SimpleResult/simpleresult
2016-01-14 17:48:00,523 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity235876814/.staging/job_local235876814_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:00,524 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity235876814/.staging/job_local235876814_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:00,571 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local235876814_0008/job_local235876814_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:00,571 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local235876814_0008/job_local235876814_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:00,574 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local235876814_0008
2016-01-14 17:48:00,574 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:00,582 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt
2016-01-14 17:48:00,604 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:00,604 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:00,617 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BE61D66B71694A99BBAA7EE1D510151D, ordinal: 0
2016-01-14 17:48:00,619 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:48:00,619 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:48:00,619 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BE61D66B71694A99BBAA7EE1D510151D, mem on start (mb), free: 331, total: 542, max: 672
2016-01-14 17:48:00,697 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BE61D66B71694A99BBAA7EE1D510151D, mem on close (mb), free: 327, total: 542, max: 672
2016-01-14 17:48:00,714 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:00,714 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:00,723 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E7E3B6C9F4A54258B01F9DFE0D883038, ordinal: 1
2016-01-14 17:48:00,723 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:48:00,724 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult"]
2016-01-14 17:48:00,724 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E7E3B6C9F4A54258B01F9DFE0D883038, mem on start (mb), free: 320, total: 542, max: 672
2016-01-14 17:48:00,733 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E7E3B6C9F4A54258B01F9DFE0D883038, mem on close (mb), free: 319, total: 542, max: 672
2016-01-14 17:48:00,750 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult/_temporary
2016-01-14 17:48:00,750 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.298
2016-01-14 17:48:00,773 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult
2016-01-14 17:48:00,788 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:00,789 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:00,821 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 17:48:00,821 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:48:00,822 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:00,831 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:00,831 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:00,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilterAll/filterall"]
2016-01-14 17:48:00,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:00,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:00,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:00,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...m/testFilterAll/filterall
2016-01-14 17:48:00,893 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1603744814/.staging/job_local1603744814_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:00,893 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1603744814/.staging/job_local1603744814_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:00,930 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1603744814_0009/job_local1603744814_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:00,930 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1603744814_0009/job_local1603744814_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:00,931 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1603744814_0009
2016-01-14 17:48:00,933 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:00,938 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:48:00,945 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:00,946 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:00,952 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5183ED91E8F485CA33488EC35224968, ordinal: 0
2016-01-14 17:48:00,953 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:00,953 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilterAll/filterall"]
2016-01-14 17:48:00,953 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5183ED91E8F485CA33488EC35224968, mem on start (mb), free: 269, total: 542, max: 672
2016-01-14 17:48:00,955 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5183ED91E8F485CA33488EC35224968, mem on close (mb), free: 269, total: 542, max: 672
2016-01-14 17:48:00,976 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilterAll/filterall/_temporary
2016-01-14 17:48:00,977 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.145
2016-01-14 17:48:00,999 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testFilterAll/filterall
2016-01-14 17:48:01,018 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:01,019 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:01,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-01-14 17:48:01,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:01,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:01,073 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:01,073 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:48:01,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-01-14 17:48:01,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:01,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:01,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:01,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...own/simplerelativeunknown
2016-01-14 17:48:01,143 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1272927160/.staging/job_local1272927160_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:01,144 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1272927160/.staging/job_local1272927160_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:01,192 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1272927160_0010/job_local1272927160_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:01,192 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1272927160_0010/job_local1272927160_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:01,193 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1272927160_0010
2016-01-14 17:48:01,194 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:01,202 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt
2016-01-14 17:48:01,228 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:01,228 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:01,234 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B9E6A764E53E469D9D621B81083D0463, ordinal: 0
2016-01-14 17:48:01,235 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:48:01,235 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:-1]]
2016-01-14 17:48:01,235 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B9E6A764E53E469D9D621B81083D0463, mem on start (mb), free: 329, total: 542, max: 672
2016-01-14 17:48:01,237 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B9E6A764E53E469D9D621B81083D0463, mem on close (mb), free: 329, total: 542, max: 672
2016-01-14 17:48:01,254 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:01,254 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:01,260 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A867879D81314FFCAF2050329122C369, ordinal: 1
2016-01-14 17:48:01,261 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:-1]]
2016-01-14 17:48:01,261 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-01-14 17:48:01,261 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A867879D81314FFCAF2050329122C369, mem on start (mb), free: 322, total: 542, max: 672
2016-01-14 17:48:01,270 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A867879D81314FFCAF2050329122C369, mem on close (mb), free: 321, total: 542, max: 672
2016-01-14 17:48:01,291 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown/_temporary
2016-01-14 17:48:01,291 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.217
2016-01-14 17:48:01,321 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown
2016-01-14 17:48:01,335 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:01,336 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:01,378 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-01-14 17:48:01,378 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:01,379 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:01,396 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 17:48:01,396 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/upper.txt"]
2016-01-14 17:48:01,397 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:48:01,398 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup"]
2016-01-14 17:48:01,398 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: false
2016-01-14 17:48:01,399 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 17:48:01,399 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 17:48:01,400 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...estCoGroup/complexcogroup
2016-01-14 17:48:01,463 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1709159769/.staging/job_local1709159769_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:01,463 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1709159769/.staging/job_local1709159769_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:01,499 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1709159769_0011/job_local1709159769_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:01,499 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1709159769_0011/job_local1709159769_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:01,501 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted hadoop job: job_local1709159769_0011
2016-01-14 17:48:01,501 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tracking url: http://localhost:8080/
2016-01-14 17:48:01,507 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/upper.txt
2016-01-14 17:48:01,526 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:01,526 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:01,534 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CE964E85B8154C569C8DBAF382B8FF79, ordinal: 0
2016-01-14 17:48:01,535 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/upper.txt"]
2016-01-14 17:48:01,535 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-01-14 17:48:01,535 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE964E85B8154C569C8DBAF382B8FF79, mem on start (mb), free: 330, total: 542, max: 672
2016-01-14 17:48:01,537 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE964E85B8154C569C8DBAF382B8FF79, mem on close (mb), free: 330, total: 542, max: 672
2016-01-14 17:48:01,547 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt
2016-01-14 17:48:01,574 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:01,575 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:01,583 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CE964E85B8154C569C8DBAF382B8FF79, ordinal: 0
2016-01-14 17:48:01,584 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-01-14 17:48:01,584 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-01-14 17:48:01,584 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE964E85B8154C569C8DBAF382B8FF79, mem on start (mb), free: 229, total: 542, max: 672
2016-01-14 17:48:01,586 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE964E85B8154C569C8DBAF382B8FF79, mem on close (mb), free: 229, total: 542, max: 672
2016-01-14 17:48:01,603 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:01,603 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:01,610 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BF746CD0F9664603A65EB37A88BF43AC, ordinal: 1
2016-01-14 17:48:01,611 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-01-14 17:48:01,611 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup"]
2016-01-14 17:48:01,611 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BF746CD0F9664603A65EB37A88BF43AC, mem on start (mb), free: 223, total: 542, max: 672
2016-01-14 17:48:01,618 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 17:48:01,618 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 17:48:01,620 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BF746CD0F9664603A65EB37A88BF43AC, mem on close (mb), free: 221, total: 542, max: 672
2016-01-14 17:48:01,644 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup/_temporary
2016-01-14 17:48:01,646 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:00.248
2016-01-14 17:48:01,705 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup
2016-01-14 17:48:01,719 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:01,719 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:01,744 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 17:48:01,745 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:48:01,745 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:01,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:01,753 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:01,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testReplace/replace"]
2016-01-14 17:48:01,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:01,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:01,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:01,755 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...tform/testReplace/replace
2016-01-14 17:48:01,816 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1975901412/.staging/job_local1975901412_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:01,817 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1975901412/.staging/job_local1975901412_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:01,861 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1975901412_0012/job_local1975901412_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:01,861 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1975901412_0012/job_local1975901412_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:01,862 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1975901412_0012
2016-01-14 17:48:01,867 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:01,871 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:48:01,878 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:01,878 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:01,887 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D745955A05F4437D956C97D883C7E4ED, ordinal: 0
2016-01-14 17:48:01,888 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:01,888 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testReplace/replace"]
2016-01-14 17:48:01,889 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D745955A05F4437D956C97D883C7E4ED, mem on start (mb), free: 393, total: 542, max: 672
2016-01-14 17:48:01,893 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D745955A05F4437D956C97D883C7E4ED, mem on close (mb), free: 393, total: 542, max: 672
2016-01-14 17:48:01,914 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testReplace/replace/_temporary
2016-01-14 17:48:01,914 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.161
2016-01-14 17:48:01,940 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testReplace/replace
2016-01-14 17:48:01,952 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:01,953 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:01,985 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 17:48:01,985 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:01,986 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:01,996 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 17:48:01,997 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:48:01,997 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2"]
2016-01-14 17:48:01,997 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 17:48:01,997 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 17:48:01,997 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 17:48:01,998 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...latform/testCount2/count2
2016-01-14 17:48:02,051 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1103280907/.staging/job_local1103280907_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,051 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1103280907/.staging/job_local1103280907_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,088 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1103280907_0013/job_local1103280907_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,089 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1103280907_0013/job_local1103280907_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,090 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local1103280907_0013
2016-01-14 17:48:02,092 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 17:48:02,096 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt
2016-01-14 17:48:02,111 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:02,111 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CA64DCEE8D1945DDB722615E25D67B59, ordinal: 0
2016-01-14 17:48:02,116 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:48:02,116 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:48:02,118 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA64DCEE8D1945DDB722615E25D67B59, mem on start (mb), free: 244, total: 542, max: 672
2016-01-14 17:48:02,120 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA64DCEE8D1945DDB722615E25D67B59, mem on close (mb), free: 244, total: 542, max: 672
2016-01-14 17:48:02,134 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:02,134 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,139 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E73B6EACE9D44C25A11CACC3756232AA, ordinal: 1
2016-01-14 17:48:02,140 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:48:02,140 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2"]
2016-01-14 17:48:02,140 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E73B6EACE9D44C25A11CACC3756232AA, mem on start (mb), free: 237, total: 542, max: 672
2016-01-14 17:48:02,149 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E73B6EACE9D44C25A11CACC3756232AA, mem on close (mb), free: 237, total: 542, max: 672
2016-01-14 17:48:02,169 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2/_temporary
2016-01-14 17:48:02,170 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.173
2016-01-14 17:48:02,224 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount2/count2
2016-01-14 17:48:02,241 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:02,241 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:02,279 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-01-14 17:48:02,280 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:02,280 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:02,297 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 17:48:02,297 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:48:02,298 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3"]
2016-01-14 17:48:02,298 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 17:48:02,298 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 17:48:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 17:48:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...latform/testCount3/count3
2016-01-14 17:48:02,358 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1463095038/.staging/job_local1463095038_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,358 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1463095038/.staging/job_local1463095038_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,390 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1463095038_0014/job_local1463095038_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,390 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1463095038_0014/job_local1463095038_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,392 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local1463095038_0014
2016-01-14 17:48:02,392 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 17:48:02,397 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt
2016-01-14 17:48:02,411 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:02,411 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,417 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5C5BC86B5924F4BB4B19F370CD84468, ordinal: 0
2016-01-14 17:48:02,417 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:48:02,417 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:48:02,417 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5C5BC86B5924F4BB4B19F370CD84468, mem on start (mb), free: 305, total: 542, max: 672
2016-01-14 17:48:02,420 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5C5BC86B5924F4BB4B19F370CD84468, mem on close (mb), free: 305, total: 542, max: 672
2016-01-14 17:48:02,435 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:02,436 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,441 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A023166CB0DA4F46AD9298A61FBDCA6A, ordinal: 1
2016-01-14 17:48:02,441 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:48:02,442 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3"]
2016-01-14 17:48:02,442 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A023166CB0DA4F46AD9298A61FBDCA6A, mem on start (mb), free: 299, total: 542, max: 672
2016-01-14 17:48:02,453 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A023166CB0DA4F46AD9298A61FBDCA6A, mem on close (mb), free: 298, total: 542, max: 672
2016-01-14 17:48:02,479 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3/_temporary
2016-01-14 17:48:02,480 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.182
2016-01-14 17:48:02,522 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount3/count3
2016-01-14 17:48:02,537 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:02,538 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:02,563 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 17:48:02,563 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:02,563 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:02,576 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 17:48:02,576 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:48:02,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4"]
2016-01-14 17:48:02,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 17:48:02,578 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 17:48:02,579 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 17:48:02,579 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...latform/testCount4/count4
2016-01-14 17:48:02,643 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1860872718/.staging/job_local1860872718_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,643 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1860872718/.staging/job_local1860872718_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,676 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1860872718_0015/job_local1860872718_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,676 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1860872718_0015/job_local1860872718_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,678 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local1860872718_0015
2016-01-14 17:48:02,678 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 17:48:02,683 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt
2016-01-14 17:48:02,701 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:02,701 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,706 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FB623D0D0F08478B89AD7D87F14622BA, ordinal: 0
2016-01-14 17:48:02,706 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-01-14 17:48:02,707 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:48:02,707 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FB623D0D0F08478B89AD7D87F14622BA, mem on start (mb), free: 319, total: 532, max: 672
2016-01-14 17:48:02,709 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FB623D0D0F08478B89AD7D87F14622BA, mem on close (mb), free: 319, total: 532, max: 672
2016-01-14 17:48:02,725 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:02,725 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,732 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B2CDA1D46498408D8A0A4F11B44D2B26, ordinal: 1
2016-01-14 17:48:02,733 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 17:48:02,734 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4"]
2016-01-14 17:48:02,734 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B2CDA1D46498408D8A0A4F11B44D2B26, mem on start (mb), free: 313, total: 532, max: 672
2016-01-14 17:48:02,745 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B2CDA1D46498408D8A0A4F11B44D2B26, mem on close (mb), free: 311, total: 532, max: 672
2016-01-14 17:48:02,767 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4/_temporary
2016-01-14 17:48:02,768 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.191
2016-01-14 17:48:02,814 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount4/count4
2016-01-14 17:48:02,826 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:02,827 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:02,850 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.020
2016-01-14 17:48:02,851 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:48:02,851 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:02,858 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:02,858 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:02,858 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilter/filter"]
2016-01-14 17:48:02,859 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:02,859 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:02,859 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:02,860 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...latform/testFilter/filter
2016-01-14 17:48:02,912 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1770744891/.staging/job_local1770744891_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,913 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity1770744891/.staging/job_local1770744891_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,944 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1770744891_0016/job_local1770744891_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:02,944 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1770744891_0016/job_local1770744891_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:02,945 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1770744891_0016
2016-01-14 17:48:02,945 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:02,949 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:48:02,955 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:02,955 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:02,960 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E5865196B40B4A2691DCE669D722C8F1, ordinal: 0
2016-01-14 17:48:02,961 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:02,961 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilter/filter"]
2016-01-14 17:48:02,961 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E5865196B40B4A2691DCE669D722C8F1, mem on start (mb), free: 260, total: 532, max: 672
2016-01-14 17:48:02,963 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E5865196B40B4A2691DCE669D722C8F1, mem on close (mb), free: 260, total: 532, max: 672
2016-01-14 17:48:02,979 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilter/filter/_temporary
2016-01-14 17:48:02,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.121
2016-01-14 17:48:03,001 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testFilter/filter
2016-01-14 17:48:03,015 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:48:03,015 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 17:48:03,046 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-01-14 17:48:03,047 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:48:03,047 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:48:03,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 17:48:03,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:03,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple"]
2016-01-14 17:48:03,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 17:48:03,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 17:48:03,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 17:48:03,061 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...latform/testSimple/simple
2016-01-14 17:48:03,115 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity2053944114/.staging/job_local2053944114_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:03,115 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/tmp/cascading/staging/teamcity2053944114/.staging/job_local2053944114_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:03,147 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2053944114_0017/job_local2053944114_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 17:48:03,147 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2053944114_0017/job_local2053944114_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 17:48:03,148 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local2053944114_0017
2016-01-14 17:48:03,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 17:48:03,153 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-01-14 17:48:03,172 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 17:48:03,172 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 17:48:03,178 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E958C10525804E9D8CBEDEDAF26C2E4E, ordinal: 0
2016-01-14 17:48:03,178 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:48:03,179 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:48:03,179 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E958C10525804E9D8CBEDEDAF26C2E4E, mem on start (mb), free: 329, total: 542, max: 672
2016-01-14 17:48:03,181 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E958C10525804E9D8CBEDEDAF26C2E4E, mem on close (mb), free: 329, total: 542, max: 672
2016-01-14 17:48:03,194 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 17:48:03,194 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 17:48:03,200 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DB2B4058FC334DBEB49FF62FF1778855, ordinal: 1
2016-01-14 17:48:03,200 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 17:48:03,200 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple"]
2016-01-14 17:48:03,201 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DB2B4058FC334DBEB49FF62FF1778855, mem on start (mb), free: 323, total: 542, max: 672
2016-01-14 17:48:03,209 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DB2B4058FC334DBEB49FF62FF1778855, mem on close (mb), free: 321, total: 542, max: 672
2016-01-14 17:48:03,226 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple/_temporary
2016-01-14 17:48:03,226 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.167
2016-01-14 17:48:03,247 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimple/simple