2016-05-17 22:29:30,557 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-17 22:29:30,577 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.stats.hadoop.HadoopStatsPlatformTest, with platform: hadoop2-mr1
2016-05-17 22:29:30,598 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-17 22:29:31,394 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-05-17 22:29:31,986 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-17 22:29:36,946 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-05-17 22:29:38,171 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-05-17 22:29:39,309 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-05-17 22:29:40,442 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-05-17 22:29:42,988 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-17 22:29:43,098 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:29:43,099 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-17 22:29:43,164 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: EE24584E5F9D49898A824175093B9019
2016-05-17 22:29:43,328 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.128
2016-05-17 22:29:43,331 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-17 22:29:43,331 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 22:29:43,477 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:29:43,478 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-17 22:29:43,560 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.076
2016-05-17 22:29:43,563 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-17 22:29:43,563 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 22:29:43,609 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-17 22:29:43,609 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-05-17 22:29:43,614 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-05-17 22:29:43,614 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-05-17 22:29:43,614 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-05-17 22:29:43,615 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-05-17 22:29:43,615 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-05-17 22:29:43,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] at least one sink is marked for delete
2016-05-17 22:29:43,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 22:29:43,615 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] at least one sink is marked for delete
2016-05-17 22:29:43,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 22:29:43,634 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting
2016-05-17 22:29:43,634 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting
2016-05-17 22:29:43,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/apache.10.txt"]
2016-05-17 22:29:43,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/apache.10.txt"]
2016-05-17 22:29:43,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2"]
2016-05-17 22:29:43,635 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1"]
2016-05-17 22:29:43,636 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] parallel execution of steps is enabled: true
2016-05-17 22:29:43,636 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executing total steps: 2
2016-05-17 22:29:43,636 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] allocating management threads: 2
2016-05-17 22:29:43,636 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] parallel execution of steps is enabled: true
2016-05-17 22:29:43,637 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executing total steps: 2
2016-05-17 22:29:43,637 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] allocating management threads: 2
2016-05-17 22:29:43,638 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (1/2)
2016-05-17 22:29:43,640 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (1/2)
2016-05-17 22:29:44,384 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463524175092_0001
2016-05-17 22:29:44,386 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:42580/proxy/application_1463524175092_0001/
2016-05-17 22:29:45,353 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463524175092_0002
2016-05-17 22:29:45,354 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:42580/proxy/application_1463524175092_0002/
2016-05-17 22:30:10,277 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0002_01_000005 is : 143
2016-05-17 22:30:10,383 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0001_01_000002 is : 143
2016-05-17 22:30:10,693 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0001_01_000003 is : 143
2016-05-17 22:30:11,751 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0002_01_000004 is : 143
2016-05-17 22:30:12,714 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0001_01_000005 is : 143
2016-05-17 22:30:12,842 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0001_01_000004 is : 143
2016-05-17 22:30:13,840 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0002_01_000002 is : 143
2016-05-17 22:30:13,956 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0002_01_000003 is : 143
2016-05-17 22:30:20,251 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0002_01_000006 is : 143
2016-05-17 22:30:21,471 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-05-17 22:30:21,490 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-05-17 22:30:21,752 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463524175092_0003
2016-05-17 22:30:21,752 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:42580/proxy/application_1463524175092_0003/
2016-05-17 22:30:22,134 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463524175092_0004
2016-05-17 22:30:22,134 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:42580/proxy/application_1463524175092_0004/
2016-05-17 22:30:39,286 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0003_01_000002 is : 143
2016-05-17 22:30:40,834 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0004_01_000002 is : 143
2016-05-17 22:30:46,196 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0003_01_000003 is : 143
2016-05-17 22:30:47,496 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1/_temporary
2016-05-17 22:30:47,498 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] completed in: 01:03.853, using cpu time: 00:08.520
2016-05-17 22:30:47,499 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-05-17 22:30:48,604 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463524175092_0004_01_000003 is : 143
2016-05-17 22:30:49,830 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2/_temporary
2016-05-17 22:30:49,832 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] completed in: 01:06.190, using cpu time: 00:07.820
2016-05-17 22:30:49,833 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-05-17 22:30:53,375 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:AB6D1] retrieved task reports: 4
2016-05-17 22:30:53,378 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:AB6D1] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-05-17 22:30:53,379 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:AB6D1] all 4 children are in finished state, have captured final details: true
2016-05-17 22:30:53,390 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:DA281] retrieved task reports: 1
2016-05-17 22:30:53,391 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:DA281] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-17 22:30:53,391 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:DA281] all 1 children are in finished state, have captured final details: true
2016-05-17 22:30:53,434 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:FFA4E] retrieved task reports: 1
2016-05-17 22:30:53,435 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:FFA4E] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-17 22:30:53,435 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:FFA4E] all 1 children are in finished state, have captured final details: true
2016-05-17 22:30:53,441 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:CF571] retrieved task reports: 1
2016-05-17 22:30:53,441 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:CF571] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-17 22:30:53,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:CF571] all 1 children are in finished state, have captured final details: true
2016-05-17 22:30:56,656 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F9A4D] retrieved task reports: 4
2016-05-17 22:30:56,657 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F9A4D] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-05-17 22:30:56,657 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F9A4D] all 4 children are in finished state, have captured final details: true
2016-05-17 22:30:56,668 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F344A] retrieved task reports: 1
2016-05-17 22:30:56,669 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F344A] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-17 22:30:56,669 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F344A] all 1 children are in finished state, have captured final details: true
2016-05-17 22:30:56,812 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:AEF20] retrieved task reports: 1
2016-05-17 22:30:56,813 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:AEF20] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-17 22:30:56,813 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:AEF20] all 1 children are in finished state, have captured final details: true
2016-05-17 22:30:56,823 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B9DA2] retrieved task reports: 1
2016-05-17 22:30:56,823 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B9DA2] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-17 22:30:56,824 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B9DA2] all 1 children are in finished state, have captured final details: true
2016-05-17 22:30:56,830 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2
2016-05-17 22:30:56,837 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1