2016-01-14 16:59:12,086 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 16:59:12,117 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 16:59:12,150 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 16:59:13,025 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 16:59:13,556 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 16:59:18,459 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 16:59:19,673 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 16:59:20,824 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 16:59:21,960 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 16:59:24,513 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 16:59:24,604 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:59:24,606 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 16:59:24,672 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 3B59BB82EABD43C09AE7231984927504
2016-01-14 16:59:24,864 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.155
2016-01-14 16:59:24,868 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 16:59:24,869 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 16:59:25,022 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 16:59:25,128 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.098
2016-01-14 16:59:25,130 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 16:59:25,131 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 16:59:25,180 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 16:59:25,181 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 16:59:25,185 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 16:59:25,186 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 16:59:25,186 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 16:59:25,188 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 16:59:25,188 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 16:59:25,188 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 16:59:25,189 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 16:59:25,189 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 16:59:25,189 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 16:59:25,208 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 16:59:25,208 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 16:59:25,209 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 16:59:25,209 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/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 16:59:25,210 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 16:59:25,211 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 16:59:25,211 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 16:59:25,209 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 16:59:25,213 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/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 16:59:25,214 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 16:59:25,214 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 16:59:25,215 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 16:59:25,215 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 16:59:25,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 16:59:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452790756629_0001
2016-01-14 16:59:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452790756629_0002
2016-01-14 16:59:26,031 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:44070/proxy/application_1452790756629_0002/
2016-01-14 16:59:26,030 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:44070/proxy/application_1452790756629_0001/
2016-01-14 16:59:54,701 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0001_01_000003 is : 143
2016-01-14 16:59:54,761 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0002_01_000003 is : 143
2016-01-14 16:59:54,980 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0002_01_000005 is : 143
2016-01-14 16:59:55,036 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0001_01_000002 is : 143
2016-01-14 16:59:55,046 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0002_01_000004 is : 143
2016-01-14 16:59:55,086 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0002_01_000002 is : 143
2016-01-14 17:00:02,130 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0001_01_000006 is : 143
2016-01-14 17:00:03,221 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0002_01_000006 is : 143
2016-01-14 17:00:03,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 17:00:03,603 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452790756629_0003
2016-01-14 17:00:03,604 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:44070/proxy/application_1452790756629_0003/
2016-01-14 17:00:04,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 17:00:04,551 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452790756629_0004
2016-01-14 17:00:04,551 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:44070/proxy/application_1452790756629_0004/
2016-01-14 17:00:22,206 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0003_01_000002 is : 143
2016-01-14 17:00:23,669 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0004_01_000002 is : 143
2016-01-14 17:00:30,381 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0003_01_000003 is : 143
2016-01-14 17:00:31,755 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/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 17:00:31,757 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:06.537, using cpu time: 00:08.310
2016-01-14 17:00:31,758 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 17:00:31,981 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452790756629_0004_01_000003 is : 143
2016-01-14 17:00:33,210 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/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 17:00:33,213 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:07.996, using cpu time: 00:07.110
2016-01-14 17:00:33,213 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 17:00:36,743 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A2CCD] retrieved task reports: 4
2016-01-14 17:00:36,746 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A2CCD] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-01-14 17:00:36,747 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A2CCD] all 4 children are in finished state, have captured final details: true
2016-01-14 17:00:36,758 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E1C25] retrieved task reports: 1
2016-01-14 17:00:36,759 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E1C25] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:00:36,759 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E1C25] all 1 children are in finished state, have captured final details: true
2016-01-14 17:00:36,805 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:FBC11] retrieved task reports: 1
2016-01-14 17:00:36,806 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:FBC11] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 17:00:36,806 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:FBC11] all 1 children are in finished state, have captured final details: true
2016-01-14 17:00:36,812 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A8F95] retrieved task reports: 1
2016-01-14 17:00:36,813 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A8F95] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 17:00:36,813 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A8F95] all 1 children are in finished state, have captured final details: true
2016-01-14 17:00:40,042 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF302] retrieved task reports: 4
2016-01-14 17:00:40,043 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF302] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-01-14 17:00:40,043 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AF302] all 4 children are in finished state, have captured final details: true
2016-01-14 17:00:40,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:BB899] retrieved task reports: 1
2016-01-14 17:00:40,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:BB899] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:00:40,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:BB899] all 1 children are in finished state, have captured final details: true
2016-01-14 17:00:40,209 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C9DB0] retrieved task reports: 1
2016-01-14 17:00:40,209 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C9DB0] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 17:00:40,209 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C9DB0] all 1 children are in finished state, have captured final details: true
2016-01-14 17:00:40,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D5DEA] retrieved task reports: 1
2016-01-14 17:00:40,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D5DEA] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 17:00:40,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D5DEA] all 1 children are in finished state, have captured final details: true
2016-01-14 17:00:40,224 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/cascadingstatsplatform/testStatsCounters/flowstats2
2016-01-14 17:00:40,231 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/cascadingstatsplatform/testStatsCounters/flowstats1