2016-01-14 21:34:48,994 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 21:34:49,023 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.hadoop.HadoopStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 21:34:49,054 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 21:34:49,910 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 21:34:50,623 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 21:34:51,170 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 21:34:54,250 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 21:34:54,397 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 21:34:54,510 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 21:34:54,626 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 21:35:11,699 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 21:35:11,809 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:35:11,810 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:35:11,880 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 3C7CB71783F1465D98BDCCF63490EAC1
2016-01-14 21:35:12,061 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.144
2016-01-14 21:35:12,065 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 21:35:12,067 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 21:35:12,210 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:35:12,210 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:35:12,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.090
2016-01-14 21:35:12,310 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 21:35:12,311 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 21:35:12,354 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 21:35:12,354 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 21:35:12,358 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 21:35:12,358 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 21:35:12,358 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 21:35:12,359 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 21:35:12,359 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 21:35:12,360 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 21:35:12,359 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 21:35:12,360 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:35:12,360 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:35:12,383 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 21:35:12,383 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 21:35:12,384 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] 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:35:12,384 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] 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:35:12,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 21:35:12,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 21:35:12,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 21:35:12,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 21:35:12,384 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 21:35:12,386 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 21:35:12,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 21:35:12,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 21:35:12,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 21:35:12,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 21:35:13,317 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452807306198_0002
2016-01-14 21:35:13,317 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:60981/proxy/application_1452807306198_0002/
2016-01-14 21:35:13,456 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452807306198_0001
2016-01-14 21:35:13,456 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:60981/proxy/application_1452807306198_0001/
2016-01-14 21:35:38,458 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0001_01_000003 is : 143
2016-01-14 21:35:38,737 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0001_01_000002 is : 143
2016-01-14 21:35:40,442 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0001_01_000005 is : 143
2016-01-14 21:35:40,766 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0001_01_000004 is : 143
2016-01-14 21:35:42,885 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0002_01_000003 is : 143
2016-01-14 21:35:43,025 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0002_01_000004 is : 143
2016-01-14 21:35:43,301 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0002_01_000005 is : 143
2016-01-14 21:35:43,345 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0002_01_000002 is : 143
2016-01-14 21:35:48,340 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0001_01_000006 is : 143
2016-01-14 21:35:49,663 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 21:35:49,963 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452807306198_0003
2016-01-14 21:35:49,963 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:60981/proxy/application_1452807306198_0003/
2016-01-14 21:35:51,359 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0002_01_000006 is : 143
2016-01-14 21:35:52,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 21:35:53,156 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452807306198_0004
2016-01-14 21:35:53,156 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:60981/proxy/application_1452807306198_0004/
2016-01-14 21:36:07,642 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0003_01_000002 is : 143
2016-01-14 21:36:12,361 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0004_01_000002 is : 143
2016-01-14 21:36:15,385 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0003_01_000003 is : 143
2016-01-14 21:36:16,722 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/hadoopstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 21:36:16,725 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:04.330, using cpu time: 00:08.740
2016-01-14 21:36:16,726 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 21:36:18,974 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807306198_0004_01_000003 is : 143
2016-01-14 21:36:20,216 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/hadoopstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 21:36:20,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:07.826, using cpu time: 00:08.190
2016-01-14 21:36:20,218 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 21:36:23,751 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F8C76] retrieved task reports: 4
2016-01-14 21:36:23,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F8C76] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-01-14 21:36:23,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F8C76] all 4 children are in finished state, have captured final details: true
2016-01-14 21:36:23,766 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:AD47D] retrieved task reports: 1
2016-01-14 21:36:23,767 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:AD47D] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 21:36:23,767 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:AD47D] all 1 children are in finished state, have captured final details: true
2016-01-14 21:36:23,976 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:ADC03] retrieved task reports: 1
2016-01-14 21:36:23,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:ADC03] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 21:36:23,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:ADC03] all 1 children are in finished state, have captured final details: true
2016-01-14 21:36:23,989 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B667C] retrieved task reports: 1
2016-01-14 21:36:23,990 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B667C] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 21:36:23,990 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B667C] all 1 children are in finished state, have captured final details: true
2016-01-14 21:36:27,181 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:CF6DC] retrieved task reports: 4
2016-01-14 21:36:27,182 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:CF6DC] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-01-14 21:36:27,182 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:CF6DC] all 4 children are in finished state, have captured final details: true
2016-01-14 21:36:27,191 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F9C83] retrieved task reports: 1
2016-01-14 21:36:27,192 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F9C83] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 21:36:27,192 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F9C83] all 1 children are in finished state, have captured final details: true
2016-01-14 21:36:27,332 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:CE5C4] retrieved task reports: 1
2016-01-14 21:36:27,334 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:CE5C4] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 21:36:27,334 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:CE5C4] all 1 children are in finished state, have captured final details: true
2016-01-14 21:36:27,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AB436] retrieved task reports: 1
2016-01-14 21:36:27,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AB436] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 21:36:27,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AB436] all 1 children are in finished state, have captured final details: true
2016-01-14 21:36:27,348 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/hadoopstatsplatform/testStatsCounters/flowstats1
2016-01-14 21:36:27,354 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/hadoopstatsplatform/testStatsCounters/flowstats2