2016-01-14 17:00:41,766 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 17:00:41,793 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.hadoop.HadoopStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 17:00:41,826 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 17:00:42,670 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
Formatting using clusterid: testClusterID
2016-01-14 17:00:43,205 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 17:00:48,158 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 17:00:49,424 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 17:00:50,559 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 17:00:51,699 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 17:00:54,249 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 17:00:54,337 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:00:54,338 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:00:54,404 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: BC68CA21C09444F8B81C18A4E200C107
2016-01-14 17:00:54,578 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.137
2016-01-14 17:00:54,582 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 17:00:54,583 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:00:54,733 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:00:54,734 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:00:54,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.091
2016-01-14 17:00:54,835 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 17:00:54,835 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:00:54,879 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 17:00:54,880 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 17:00:54,885 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 17:00:54,885 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 17:00:54,886 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 17:00:54,887 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 17:00:54,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 17:00:54,886 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 17:00:54,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:00:54,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 17:00:54,888 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:00:54,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 17:00:54,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 17:00:54,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:00:54,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/classes/test/data/apache.10.txt"]
2016-01-14 17:00:54,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 17:00:54,938 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 17:00:54,938 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 17:00:54,938 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 17:00:54,938 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 17:00:54,938 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 17:00:54,940 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 17:00:54,941 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 17:00:54,940 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 17:00:54,943 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 17:00:55,713 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452790846268_0001
2016-01-14 17:00:55,713 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:55953/proxy/application_1452790846268_0001/
2016-01-14 17:00:56,660 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452790846268_0002
2016-01-14 17:00:56,660 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:55953/proxy/application_1452790846268_0002/
2016-01-14 17:01:23,381 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0001_01_000005 is : 143
2016-01-14 17:01:23,621 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0001_01_000004 is : 143
2016-01-14 17:01:24,426 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0002_01_000004 is : 143
2016-01-14 17:01:24,610 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0002_01_000005 is : 143
2016-01-14 17:01:24,729 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0002_01_000002 is : 143
2016-01-14 17:01:25,019 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0001_01_000002 is : 143
2016-01-14 17:01:25,043 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0002_01_000003 is : 143
2016-01-14 17:01:25,057 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0001_01_000003 is : 143
2016-01-14 17:01:32,022 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0001_01_000006 is : 143
2016-01-14 17:01:32,524 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0002_01_000006 is : 143
2016-01-14 17:01:33,269 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 17:01:33,477 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452790846268_0003
2016-01-14 17:01:33,477 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:55953/proxy/application_1452790846268_0003/
2016-01-14 17:01:33,720 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 17:01:33,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452790846268_0004
2016-01-14 17:01:33,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:55953/proxy/application_1452790846268_0004/
2016-01-14 17:01:51,959 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0003_01_000002 is : 143
2016-01-14 17:01:53,415 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0004_01_000002 is : 143
2016-01-14 17:02:00,773 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0003_01_000003 is : 143
2016-01-14 17:02:02,077 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 17:02:02,080 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:07.135, using cpu time: 00:08.070
2016-01-14 17:02:02,081 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 17:02:02,227 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790846268_0004_01_000003 is : 143
2016-01-14 17:02:03,442 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 17:02:03,445 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:08.503, using cpu time: 00:07.240
2016-01-14 17:02:03,445 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 17:02:06,979 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A7D62] retrieved task reports: 4
2016-01-14 17:02:06,982 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A7D62] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-01-14 17:02:06,982 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A7D62] all 4 children are in finished state, have captured final details: true
2016-01-14 17:02:06,994 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F8EF5] retrieved task reports: 1
2016-01-14 17:02:06,995 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F8EF5] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:02:06,995 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F8EF5] all 1 children are in finished state, have captured final details: true
2016-01-14 17:02:07,073 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C8D9A] retrieved task reports: 1
2016-01-14 17:02:07,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C8D9A] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:02:07,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C8D9A] all 1 children are in finished state, have captured final details: true
2016-01-14 17:02:07,081 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E639D] retrieved task reports: 1
2016-01-14 17:02:07,081 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E639D] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:02:07,081 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E639D] all 1 children are in finished state, have captured final details: true
2016-01-14 17:02:10,306 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A3AA6] retrieved task reports: 4
2016-01-14 17:02:10,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A3AA6] added 4, updated: 0 slices, with duration: 00:00.000, total fetched: 4
2016-01-14 17:02:10,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A3AA6] all 4 children are in finished state, have captured final details: true
2016-01-14 17:02:10,319 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F5E4B] retrieved task reports: 1
2016-01-14 17:02:10,321 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F5E4B] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 17:02:10,321 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F5E4B] all 1 children are in finished state, have captured final details: true
2016-01-14 17:02:10,471 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF196] retrieved task reports: 1
2016-01-14 17:02:10,472 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF196] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:02:10,472 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF196] all 1 children are in finished state, have captured final details: true
2016-01-14 17:02:10,482 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF0AA] retrieved task reports: 1
2016-01-14 17:02:10,483 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF0AA] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 17:02:10,483 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF0AA] all 1 children are in finished state, have captured final details: true
2016-01-14 17:02:10,490 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2
2016-01-14 17:02:10,497 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.2.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1