2016-01-14 23:52:18,920 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 23:52:18,941 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 23:52:18,963 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 23:52:19,706 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:52:20,398 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 23:52:20,996 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:52:24,228 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:52:24,383 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:52:24,502 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:52:24,622 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:52:36,428 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:52:37,405 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:52:37,405 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 23:52:41,697 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 23:52:41,807 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:52:41,808 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:52:41,877 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: A0CA58E930BE40758556F19BB829BB81
2016-01-14 23:52:42,056 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.142
2016-01-14 23:52:42,061 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 23:52:42,062 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:52:42,220 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:52:42,335 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.107
2016-01-14 23:52:42,339 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 23:52:42,339 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:52:42,382 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 23:52:42,382 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 23:52:42,387 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 23:52:42,387 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 23:52:42,387 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 23:52:42,388 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 23:52:42,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 23:52:42,391 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 23:52:42,391 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:52:42,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 23:52:42,393 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:52:42,415 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 23:52:42,415 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 23:52:42,416 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:52:42,416 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:52:42,416 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/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 23:52:42,418 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/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 23:52:42,418 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 23:52:42,418 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 23:52:42,418 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 23:52:42,418 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 23:52:42,420 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 23:52:42,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 23:52:42,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 23:52:42,424 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 23:52:43,466 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452815556195_0002
2016-01-14 23:52:43,466 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:41529/proxy/application_1452815556195_0002/
2016-01-14 23:52:43,475 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452815556195_0001
2016-01-14 23:52:43,475 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:41529/proxy/application_1452815556195_0001/
2016-01-14 23:53:10,368 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0001_01_000004 is : 143
2016-01-14 23:53:10,591 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0001_01_000002 is : 143
2016-01-14 23:53:10,859 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0001_01_000005 is : 143
2016-01-14 23:53:13,598 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0002_01_000005 is : 143
2016-01-14 23:53:13,704 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0002_01_000004 is : 143
2016-01-14 23:53:13,798 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0002_01_000002 is : 143
2016-01-14 23:53:14,001 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0002_01_000003 is : 143
2016-01-14 23:53:19,726 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0001_01_000006 is : 143
2016-01-14 23:53:21,106 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 23:53:21,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452815556195_0003
2016-01-14 23:53:21,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:41529/proxy/application_1452815556195_0003/
2016-01-14 23:53:21,861 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0002_01_000006 is : 143
2016-01-14 23:53:23,064 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 23:53:23,236 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452815556195_0004
2016-01-14 23:53:23,236 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:41529/proxy/application_1452815556195_0004/
2016-01-14 23:53:39,701 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0003_01_000002 is : 143
2016-01-14 23:53:42,140 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0004_01_000002 is : 143
2016-01-14 23:53:47,550 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0003_01_000003 is : 143
2016-01-14 23:53:48,918 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/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 23:53:48,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:06.494, using cpu time: 00:09.200
2016-01-14 23:53:48,921 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 23:53:49,924 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452815556195_0004_01_000003 is : 143
2016-01-14 23:53:51,142 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/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 23:53:51,144 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:08.724, using cpu time: 00:08.220
2016-01-14 23:53:51,144 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 23:53:54,684 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F1765] retrieved task reports: 4
2016-01-14 23:53:54,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F1765] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-01-14 23:53:54,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:F1765] all 4 children are in finished state, have captured final details: true
2016-01-14 23:53:54,700 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C699C] retrieved task reports: 1
2016-01-14 23:53:54,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C699C] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 23:53:54,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C699C] all 1 children are in finished state, have captured final details: true
2016-01-14 23:53:54,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B628E] retrieved task reports: 1
2016-01-14 23:53:54,891 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B628E] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:53:54,891 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B628E] all 1 children are in finished state, have captured final details: true
2016-01-14 23:53:54,902 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B4C96] retrieved task reports: 1
2016-01-14 23:53:54,905 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B4C96] added 1, updated: 0 slices, with duration: 00:00.003, total fetched: 1
2016-01-14 23:53:54,905 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B4C96] all 1 children are in finished state, have captured final details: true
2016-01-14 23:53:58,103 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F404E] retrieved task reports: 4
2016-01-14 23:53:58,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F404E] added 4, updated: 0 slices, with duration: 00:00.000, total fetched: 4
2016-01-14 23:53:58,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F404E] all 4 children are in finished state, have captured final details: true
2016-01-14 23:53:58,114 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:ABD0E] retrieved task reports: 1
2016-01-14 23:53:58,114 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:ABD0E] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:53:58,114 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:ABD0E] all 1 children are in finished state, have captured final details: true
2016-01-14 23:53:58,253 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D4AE4] retrieved task reports: 1
2016-01-14 23:53:58,254 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D4AE4] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 23:53:58,254 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D4AE4] all 1 children are in finished state, have captured final details: true
2016-01-14 23:53:58,262 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A7EF3] retrieved task reports: 1
2016-01-14 23:53:58,263 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A7EF3] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 23:53:58,263 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:A7EF3] all 1 children are in finished state, have captured final details: true
2016-01-14 23:53:58,267 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/cascadingstatsplatform/testStatsCounters/flowstats2
2016-01-14 23:53:58,274 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/cascadingstatsplatform/testStatsCounters/flowstats1