2016-01-14 21:22:32,040 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 21:22:32,062 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.flow.AssemblyPlannerPlatformTest, with platform: hadoop2-mr1
2016-01-14 21:22:32,093 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-14 21:22:32,770 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 21:22:32,958 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 21:22:33,080 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:22:33,083 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 21:22:33,196 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 64DC8D5871394F158AE344487AEEDDD6
2016-01-14 21:22:33,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.121
2016-01-14 21:22:33,392 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 21:22:33,392 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:22:33,557 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 21:22:33,558 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting
2016-01-14 21:22:33,559 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 21:22:33,559 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/assemblyplannerplatform/testCompositeAssembly/composite"]
2016-01-14 21:22:33,559 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] parallel execution of steps is enabled: false
2016-01-14 21:22:33,560 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executing total steps: 1
2016-01-14 21:22:33,561 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] allocating management threads: 1
2016-01-14 21:22:33,561 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting step: (1/1) ...mpositeAssembly/composite
2016-01-14 21:22:34,135 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1926911987/.staging/job_local1926911987_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 21:22:34,146 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1926911987/.staging/job_local1926911987_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 21:22:34,353 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1926911987_0001/job_local1926911987_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 21:22:34,359 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1926911987_0001/job_local1926911987_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 21:22:34,366 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] submitted hadoop job: job_local1926911987_0001
2016-01-14 21:22:34,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] tracking url: http://localhost:8080/
2016-01-14 21:22:34,472 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-01-14 21:22:34,615 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:34,616 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:34,629 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CBA16672226C43999327BEE8CE379F29, ordinal: 0
2016-01-14 21:22:34,677 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 21:22:34,678 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 21:22:34,680 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CBA16672226C43999327BEE8CE379F29, mem on start (mb), free: 88, total: 223, max: 672
2016-01-14 21:22:34,691 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CBA16672226C43999327BEE8CE379F29, mem on close (mb), free: 88, total: 223, max: 672
2016-01-14 21:22:34,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:34,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:34,816 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DD3139529C2A40E98742FC43B40A18EE, ordinal: 1
2016-01-14 21:22:34,820 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 21:22:34,820 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/assemblyplannerplatform/testCompositeAssembly/composite"]
2016-01-14 21:22:34,821 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD3139529C2A40E98742FC43B40A18EE, mem on start (mb), free: 78, total: 223, max: 672
2016-01-14 21:22:34,841 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD3139529C2A40E98742FC43B40A18EE, mem on close (mb), free: 77, total: 223, max: 672
2016-01-14 21:22:34,875 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/assemblyplannerplatform/testCompositeAssembly/composite/_temporary
2016-01-14 21:22:34,876 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] completed in: 00:01.315
2016-01-14 21:22:34,914 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/assemblyplannerplatform/testCompositeAssembly/composite
2016-01-14 21:22:34,937 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:22:34,938 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 21:22:35,018 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.065
2016-01-14 21:22:35,020 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 21:22:35,020 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:22:35,043 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting
2016-01-14 21:22:35,043 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 21:22:35,044 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/assemblyplannerplatform/testSimpleAssembly/simple"]
2016-01-14 21:22:35,044 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] parallel execution of steps is enabled: false
2016-01-14 21:22:35,044 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executing total steps: 1
2016-01-14 21:22:35,045 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] allocating management threads: 1
2016-01-14 21:22:35,047 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting step: (1/1) ...testSimpleAssembly/simple
2016-01-14 21:22:35,151 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1012480642/.staging/job_local1012480642_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 21:22:35,155 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1012480642/.staging/job_local1012480642_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 21:22:35,227 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1012480642_0002/job_local1012480642_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 21:22:35,230 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1012480642_0002/job_local1012480642_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 21:22:35,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] submitted hadoop job: job_local1012480642_0002
2016-01-14 21:22:35,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] tracking url: http://localhost:8080/
2016-01-14 21:22:35,240 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-01-14 21:22:35,347 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:22:35,347 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:22:35,357 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F4C2E267614842A2B573645C1929E86F, ordinal: 0
2016-01-14 21:22:35,358 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 21:22:35,358 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 21:22:35,359 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F4C2E267614842A2B573645C1929E86F, mem on start (mb), free: 95, total: 323, max: 672
2016-01-14 21:22:35,361 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F4C2E267614842A2B573645C1929E86F, mem on close (mb), free: 95, total: 323, max: 672
2016-01-14 21:22:35,380 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 21:22:35,380 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 21:22:35,390 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D640E19DBBE54BC1B7616F9898B22298, ordinal: 1
2016-01-14 21:22:35,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 21:22:35,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/assemblyplannerplatform/testSimpleAssembly/simple"]
2016-01-14 21:22:35,391 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D640E19DBBE54BC1B7616F9898B22298, mem on start (mb), free: 92, total: 323, max: 672
2016-01-14 21:22:35,402 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D640E19DBBE54BC1B7616F9898B22298, mem on close (mb), free: 91, total: 323, max: 672
2016-01-14 21:22:35,423 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/assemblyplannerplatform/testSimpleAssembly/simple/_temporary
2016-01-14 21:22:35,424 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] completed in: 00:00.380
2016-01-14 21:22:35,460 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/assemblyplannerplatform/testSimpleAssembly/simple