2016-01-14 23:53:59,769 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 23:53:59,791 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.hadoop.HadoopStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 23:53:59,816 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 23:54:00,656 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 23:54:01,283 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 23:54:01,833 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:54:05,061 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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 23:54:05,219 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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 23:54:05,337 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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 23:54:05,455 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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 23:54:17,296 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:54:18,344 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:54:18,345 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:54:22,535 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 23:54:22,636 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:54:22,637 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 23:54:22,703 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 88894E30B50545A18CF3A408A2996EEB
2016-01-14 23:54:22,876 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.136
2016-01-14 23:54:22,880 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 23:54:22,881 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 23:54:23,041 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:54:23,042 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 23:54:23,161 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.111
2016-01-14 23:54:23,163 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 23:54:23,164 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 23:54:23,213 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 23:54:23,213 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 23:54:23,218 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 23:54:23,218 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 23:54:23,218 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 23:54:23,219 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 23:54:23,219 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 23:54:23,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 23:54:23,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 23:54:23,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 23:54:23,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 23:54:23,244 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 23:54:23,244 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 23:54:23,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-01-14 23:54:23,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 23:54:23,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 23:54:23,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 23:54:23,245 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 23:54:23,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-01-14 23:54:23,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 23:54:23,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 23:54:23,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 23:54:23,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 23:54:23,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 23:54:23,251 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 23:54:24,055 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452815657033_0001
2016-01-14 23:54:24,056 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:34129/proxy/application_1452815657033_0001/
2016-01-14 23:54:24,230 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452815657033_0002
2016-01-14 23:54:24,230 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:34129/proxy/application_1452815657033_0002/
2016-01-14 23:54:50,619 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0001_01_000005 is : 143
2016-01-14 23:54:51,288 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0001_01_000004 is : 143
2016-01-14 23:54:51,803 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0001_01_000003 is : 143
2016-01-14 23:54:54,138 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0002_01_000004 is : 143
2016-01-14 23:54:54,632 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0002_01_000002 is : 143
2016-01-14 23:54:54,883 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0002_01_000005 is : 143
2016-01-14 23:54:54,939 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0002_01_000003 is : 143
2016-01-14 23:54:59,977 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0001_01_000006 is : 143
2016-01-14 23:55:01,445 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 23:55:01,757 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452815657033_0003
2016-01-14 23:55:01,757 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:34129/proxy/application_1452815657033_0003/
2016-01-14 23:55:02,410 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0002_01_000006 is : 143
2016-01-14 23:55:03,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 23:55:03,771 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452815657033_0004
2016-01-14 23:55:03,771 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:34129/proxy/application_1452815657033_0004/
2016-01-14 23:55:20,325 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0003_01_000002 is : 143
2016-01-14 23:55:23,071 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0004_01_000002 is : 143
2016-01-14 23:55:29,058 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0003_01_000003 is : 143
2016-01-14 23:55:30,524 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 23:55:30,526 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:07.263, using cpu time: 00:09.310
2016-01-14 23:55:30,527 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 23:55:31,113 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815657033_0004_01_000003 is : 143
2016-01-14 23:55:32,357 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 23:55:32,359 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:09.110, using cpu time: 00:08.210
2016-01-14 23:55:32,359 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 23:55:35,919 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F72C7] retrieved task reports: 4
2016-01-14 23:55:35,922 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F72C7] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-01-14 23:55:35,922 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F72C7] all 4 children are in finished state, have captured final details: true
2016-01-14 23:55:35,934 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B8ED8] retrieved task reports: 1
2016-01-14 23:55:35,935 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B8ED8] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 23:55:35,935 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B8ED8] all 1 children are in finished state, have captured final details: true
2016-01-14 23:55:36,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:DEA0F] retrieved task reports: 1
2016-01-14 23:55:36,146 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:DEA0F] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:55:36,147 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:DEA0F] all 1 children are in finished state, have captured final details: true
2016-01-14 23:55:36,160 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:CC56A] retrieved task reports: 1
2016-01-14 23:55:36,160 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:CC56A] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:55:36,161 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:CC56A] all 1 children are in finished state, have captured final details: true
2016-01-14 23:55:39,370 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F82C4] retrieved task reports: 4
2016-01-14 23:55:39,371 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F82C4] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-01-14 23:55:39,371 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F82C4] all 4 children are in finished state, have captured final details: true
2016-01-14 23:55:39,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C5E2E] retrieved task reports: 1
2016-01-14 23:55:39,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C5E2E] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 23:55:39,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C5E2E] all 1 children are in finished state, have captured final details: true
2016-01-14 23:55:39,519 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AE3E0] retrieved task reports: 1
2016-01-14 23:55:39,520 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AE3E0] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:55:39,520 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AE3E0] all 1 children are in finished state, have captured final details: true
2016-01-14 23:55:39,528 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:EE401] retrieved task reports: 1
2016-01-14 23:55:39,529 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:EE401] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:55:39,529 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:EE401] all 1 children are in finished state, have captured final details: true
2016-01-14 23:55:39,534 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2
2016-01-14 23:55:39,541 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1