2016-01-14 19:14:03,648 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 19:14:03,677 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-01-14 19:14:03,708 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 19:14:04,553 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 19:14:05,095 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 19:14:05,716 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(158)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 19:14:08,690 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 19:14:08,835 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 19:14:08,952 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 19:14:09,068 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 19:14:26,141 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 19:14:26,244 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 19:14:26,245 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 19:14:26,318 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 8B73AEDEC4414E3EA68A5EE109AB9BFE
2016-01-14 19:14:26,491 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.135
2016-01-14 19:14:26,495 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 19:14:26,497 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 19:14:26,640 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 19:14:26,738 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.091
2016-01-14 19:14:26,741 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 19:14:26,742 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 19:14:26,785 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 19:14:26,785 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-14 19:14:26,790 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-14 19:14:26,790 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-14 19:14:26,790 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-14 19:14:26,791 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-14 19:14:26,791 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-14 19:14:26,791 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-14 19:14:26,791 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 19:14:26,792 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-14 19:14:26,792 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 19:14:26,815 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-14 19:14:26,815 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-14 19:14:26,816 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 19:14:26,816 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2016-01-14 19:14:26,816 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-01-14 19:14:26,816 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-01-14 19:14:26,816 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-14 19:14:26,817 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-14 19:14:26,817 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-14 19:14:26,817 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-14 19:14:26,818 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-14 19:14:26,818 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-14 19:14:26,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-14 19:14:26,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-14 19:14:27,628 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452798860638_0001
2016-01-14 19:14:27,629 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165.ec2.internal:59922/proxy/application_1452798860638_0001/
2016-01-14 19:14:27,810 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452798860638_0002
2016-01-14 19:14:27,810 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165.ec2.internal:59922/proxy/application_1452798860638_0002/
2016-01-14 19:14:54,776 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0001_01_000004 is : 143
2016-01-14 19:14:54,951 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0001_01_000005 is : 143
2016-01-14 19:14:55,111 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0001_01_000002 is : 143
2016-01-14 19:14:55,220 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0001_01_000003 is : 143
2016-01-14 19:14:56,794 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0002_01_000004 is : 143
2016-01-14 19:14:56,881 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0002_01_000005 is : 143
2016-01-14 19:14:57,312 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0002_01_000003 is : 143
2016-01-14 19:14:57,385 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0002_01_000002 is : 143
2016-01-14 19:15:02,646 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0001_01_000006 is : 143
2016-01-14 19:15:03,917 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-14 19:15:04,211 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452798860638_0003
2016-01-14 19:15:04,212 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165.ec2.internal:59922/proxy/application_1452798860638_0003/
2016-01-14 19:15:05,347 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0002_01_000006 is : 143
2016-01-14 19:15:06,539 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-14 19:15:06,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452798860638_0004
2016-01-14 19:15:06,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165.ec2.internal:59922/proxy/application_1452798860638_0004/
2016-01-14 19:15:21,992 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0003_01_000002 is : 143
2016-01-14 19:15:24,886 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0004_01_000002 is : 143
2016-01-14 19:15:29,135 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0003_01_000003 is : 143
2016-01-14 19:15:30,486 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-14 19:15:30,489 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:03.651, using cpu time: 00:07.890
2016-01-14 19:15:30,489 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-14 19:15:31,762 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452798860638_0004_01_000003 is : 143
2016-01-14 19:15:32,985 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-14 19:15:32,987 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:06.166, using cpu time: 00:07.040
2016-01-14 19:15:32,987 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-14 19:15:36,523 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B0207] retrieved task reports: 4
2016-01-14 19:15:36,526 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B0207] added 4, updated: 0 slices, with duration: 00:00.002, total fetched: 4
2016-01-14 19:15:36,526 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:B0207] all 4 children are in finished state, have captured final details: true
2016-01-14 19:15:36,539 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D27BE] retrieved task reports: 1
2016-01-14 19:15:36,539 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D27BE] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 19:15:36,540 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D27BE] all 1 children are in finished state, have captured final details: true
2016-01-14 19:15:36,595 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A5671] retrieved task reports: 1
2016-01-14 19:15:36,596 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A5671] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 19:15:36,596 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:A5671] all 1 children are in finished state, have captured final details: true
2016-01-14 19:15:36,602 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E4405] retrieved task reports: 1
2016-01-14 19:15:36,603 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E4405] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 19:15:36,603 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:E4405] all 1 children are in finished state, have captured final details: true
2016-01-14 19:15:39,830 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F5B84] retrieved task reports: 4
2016-01-14 19:15:39,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F5B84] added 4, updated: 0 slices, with duration: 00:00.002, total fetched: 4
2016-01-14 19:15:39,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F5B84] all 4 children are in finished state, have captured final details: true
2016-01-14 19:15:39,844 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:E58B1] retrieved task reports: 1
2016-01-14 19:15:39,845 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:E58B1] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 19:15:39,845 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:E58B1] all 1 children are in finished state, have captured final details: true
2016-01-14 19:15:39,993 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AB569] retrieved task reports: 1
2016-01-14 19:15:39,994 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AB569] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-14 19:15:39,994 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:AB569] all 1 children are in finished state, have captured final details: true
2016-01-14 19:15:40,005 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C696B] retrieved task reports: 1
2016-01-14 19:15:40,006 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C696B] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-14 19:15:40,006 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:C696B] all 1 children are in finished state, have captured final details: true
2016-01-14 19:15:40,010 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1
2016-01-14 19:15:40,017 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.3.x/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2