2016-01-14 21:33:07,653 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 21:33:07,683 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 21:33:07,714 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 21:33:08,593 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:33:09,301 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 21:33:09,851 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 21:33:13,125 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:33:13,270 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:33:13,386 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:33:13,500 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:33:30,573 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 21:33:30,679 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:33:30,680 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:33:30,756 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: ADB5083AF4214FC4A350FCA901BC13B3
2016-01-14 21:33:30,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.144
2016-01-14 21:33:30,940 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 21:33:30,941 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:33:31,079 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:33:31,172 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.086
2016-01-14 21:33:31,174 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 21:33:31,175 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:33:31,218 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 21:33:31,218 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 21:33:31,223 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 21:33:31,223 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 21:33:31,223 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 21:33:31,224 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 21:33:31,224 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 21:33:31,225 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 21:33:31,225 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 21:33:31,225 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:33:31,225 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:33:31,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 21:33:31,248 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 21:33:31,249 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:33:31,250 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/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 21:33:31,250 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 21:33:31,250 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:33:31,250 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 21:33:31,251 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/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 21:33:31,251 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 21:33:31,251 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 21:33:31,252 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 21:33:31,251 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 21:33:31,254 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 21:33:31,258 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 21:33:32,304 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452807205071_0001
2016-01-14 21:33:32,305 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:42242/proxy/application_1452807205071_0001/
2016-01-14 21:33:32,318 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452807205071_0002
2016-01-14 21:33:32,318 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:42242/proxy/application_1452807205071_0002/
2016-01-14 21:33:59,911 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0001_01_000002 is : 143
2016-01-14 21:33:59,925 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0001_01_000005 is : 143
2016-01-14 21:34:00,091 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0001_01_000003 is : 143
2016-01-14 21:34:01,315 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0002_01_000005 is : 143
2016-01-14 21:34:01,727 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0002_01_000004 is : 143
2016-01-14 21:34:02,227 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0002_01_000002 is : 143
2016-01-14 21:34:02,439 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0002_01_000003 is : 143
2016-01-14 21:34:08,838 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0001_01_000006 is : 143
2016-01-14 21:34:10,099 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 21:34:10,484 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452807205071_0003
2016-01-14 21:34:10,484 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:42242/proxy/application_1452807205071_0003/
2016-01-14 21:34:10,567 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0002_01_000006 is : 143
2016-01-14 21:34:11,765 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 21:34:11,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452807205071_0004
2016-01-14 21:34:11,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:42242/proxy/application_1452807205071_0004/
2016-01-14 21:34:28,403 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0003_01_000002 is : 143
2016-01-14 21:34:30,882 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0004_01_000002 is : 143
2016-01-14 21:34:36,202 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0003_01_000003 is : 143
2016-01-14 21:34:37,565 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/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 21:34:37,568 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:06.306, using cpu time: 00:09.190
2016-01-14 21:34:37,569 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 21:34:39,046 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452807205071_0004_01_000003 is : 143
2016-01-14 21:34:40,298 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/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 21:34:40,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:09.047, using cpu time: 00:08.030
2016-01-14 21:34:40,300 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 21:34:43,838 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B7A82] retrieved task reports: 4
2016-01-14 21:34:43,841 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B7A82] added 4, updated: 0 slices, with duration: 00:00.002, total fetched: 4
2016-01-14 21:34:43,842 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B7A82] all 4 children are in finished state, have captured final details: true
2016-01-14 21:34:43,854 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:AF55B] retrieved task reports: 1
2016-01-14 21:34:43,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:AF55B] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 21:34:43,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:AF55B] all 1 children are in finished state, have captured final details: true
2016-01-14 21:34:44,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D46E4] retrieved task reports: 1
2016-01-14 21:34:44,062 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D46E4] added 1, updated: 0 slices, with duration: 00:00.002, total fetched: 1
2016-01-14 21:34:44,062 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D46E4] all 1 children are in finished state, have captured final details: true
2016-01-14 21:34:44,072 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F98A8] retrieved task reports: 1
2016-01-14 21:34:44,073 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F98A8] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 21:34:44,073 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F98A8] all 1 children are in finished state, have captured final details: true
2016-01-14 21:34:47,266 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:E140A] retrieved task reports: 4
2016-01-14 21:34:47,268 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:E140A] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-01-14 21:34:47,269 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:E140A] all 4 children are in finished state, have captured final details: true
2016-01-14 21:34:47,278 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C7597] retrieved task reports: 1
2016-01-14 21:34:47,279 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C7597] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 21:34:47,279 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C7597] all 1 children are in finished state, have captured final details: true
2016-01-14 21:34:47,414 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A33B1] retrieved task reports: 1
2016-01-14 21:34:47,415 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A33B1] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 21:34:47,415 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A33B1] all 1 children are in finished state, have captured final details: true
2016-01-14 21:34:47,423 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F55FD] retrieved task reports: 1
2016-01-14 21:34:47,424 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F55FD] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 21:34:47,424 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F55FD] all 1 children are in finished state, have captured final details: true
2016-01-14 21:34:47,428 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/cascadingstatsplatform/testStatsCounters/flowstats2
2016-01-14 21:34:47,434 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/cascadingstatsplatform/testStatsCounters/flowstats1