2016-01-15 05:05:29,300 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-15 05:05:29,333 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.hadoop.HadoopStatsPlatformTest, with platform: hadoop2-mr1
2016-01-15 05:05:29,368 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-15 05:05:30,463 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-15 05:05:31,279 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(125)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-15 05:05:35,771 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for 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-15 05:05:35,993 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for 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-15 05:05:36,181 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for 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-15 05:05:36,366 WARN containermanager.AuxServices (AuxServices.java:serviceInit(130)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for 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-15 05:05:53,463 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-15 05:05:53,563 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-15 05:05:53,564 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-15 05:05:53,629 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 8D2594E84C1E4AA58BB39F22B33407A5
2016-01-15 05:05:53,814 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.143
2016-01-15 05:05:53,818 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-15 05:05:53,819 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-15 05:05:53,976 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-15 05:05:53,977 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-15 05:05:54,091 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.106
2016-01-15 05:05:54,093 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-15 05:05:54,093 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-15 05:05:54,140 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-15 05:05:54,141 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-01-15 05:05:54,145 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-01-15 05:05:54,146 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-01-15 05:05:54,146 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-01-15 05:05:54,147 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-01-15 05:05:54,149 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-01-15 05:05:54,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2016-01-15 05:05:54,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2016-01-15 05:05:54,150 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-15 05:05:54,150 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-15 05:05:54,187 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2016-01-15 05:05:54,187 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2016-01-15 05:05:54,188 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/classes/test/data/apache.10.txt"]
2016-01-15 05:05:54,188 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2"]
2016-01-15 05:05:54,188 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2016-01-15 05:05:54,189 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2016-01-15 05:05:54,189 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2016-01-15 05:05:54,190 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/classes/test/data/apache.10.txt"]
2016-01-15 05:05:54,190 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1"]
2016-01-15 05:05:54,190 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2016-01-15 05:05:54,191 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2016-01-15 05:05:54,191 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2016-01-15 05:05:54,192 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2016-01-15 05:05:54,192 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2016-01-15 05:05:55,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452834347961_0002
2016-01-15 05:05:55,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:51172/proxy/application_1452834347961_0002/
2016-01-15 05:05:55,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452834347961_0001
2016-01-15 05:05:55,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:51172/proxy/application_1452834347961_0001/
2016-01-15 05:06:13,391 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0002_01_000003 is : 143
2016-01-15 05:06:13,556 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0002_01_000002 is : 143
2016-01-15 05:06:14,041 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0002_01_000004 is : 143
2016-01-15 05:06:20,754 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0002_01_000006 is : 143
2016-01-15 05:06:21,934 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-01-15 05:06:22,125 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1452834347961_0003
2016-01-15 05:06:22,126 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://ip-10-167-78-165:51172/proxy/application_1452834347961_0003/
2016-01-15 05:06:44,845 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0001_01_000002 is : 143
2016-01-15 05:06:45,148 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0001_01_000005 is : 143
2016-01-15 05:06:45,314 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0001_01_000003 is : 143
2016-01-15 05:06:45,462 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0001_01_000004 is : 143
2016-01-15 05:06:52,009 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0001_01_000006 is : 143
2016-01-15 05:06:53,160 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-01-15 05:06:53,366 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1452834347961_0004
2016-01-15 05:06:53,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://ip-10-167-78-165:51172/proxy/application_1452834347961_0004/
2016-01-15 05:07:09,942 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0003_01_000002 is : 143
2016-01-15 05:07:17,896 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0003_01_000003 is : 143
2016-01-15 05:07:19,111 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2/_temporary
2016-01-15 05:07:19,114 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 01:24.917, using cpu time: 00:08.400
2016-01-15 05:07:19,114 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-01-15 05:07:36,275 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0004_01_000002 is : 143
2016-01-15 05:07:43,229 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1452834347961_0004_01_000003 is : 143
2016-01-15 05:07:44,411 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1/_temporary
2016-01-15 05:07:44,413 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:50.222, using cpu time: 00:07.910
2016-01-15 05:07:44,414 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-01-15 05:07:47,778 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2016-01-15 05:07:47,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D9230] retrieved task reports: 4
2016-01-15 05:07:47,823 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D9230] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-01-15 05:07:47,823 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D9230] all 4 children are in finished state, have captured final details: true
2016-01-15 05:07:47,836 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C32AA] retrieved task reports: 1
2016-01-15 05:07:47,837 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C32AA] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-15 05:07:47,837 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C32AA] all 1 children are in finished state, have captured final details: true
2016-01-15 05:07:51,041 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2016-01-15 05:07:51,046 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:DFA0D] retrieved task reports: 1
2016-01-15 05:07:51,046 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:DFA0D] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-15 05:07:51,047 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:DFA0D] all 1 children are in finished state, have captured final details: true
2016-01-15 05:07:51,057 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C17F8] retrieved task reports: 1
2016-01-15 05:07:51,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C17F8] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-15 05:07:51,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:C17F8] all 1 children are in finished state, have captured final details: true
2016-01-15 05:07:54,250 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2016-01-15 05:07:54,269 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F222C] retrieved task reports: 4
2016-01-15 05:07:54,270 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F222C] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-01-15 05:07:54,270 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:F222C] all 4 children are in finished state, have captured final details: true
2016-01-15 05:07:54,281 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FA027] retrieved task reports: 1
2016-01-15 05:07:54,282 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FA027] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-15 05:07:54,283 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FA027] all 1 children are in finished state, have captured final details: true
2016-01-15 05:07:54,417 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2016-01-15 05:07:54,420 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FD440] retrieved task reports: 1
2016-01-15 05:07:54,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FD440] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-01-15 05:07:54,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FD440] all 1 children are in finished state, have captured final details: true
2016-01-15 05:07:54,430 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FEAF3] retrieved task reports: 1
2016-01-15 05:07:54,431 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FEAF3] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-01-15 05:07:54,431 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FEAF3] all 1 children are in finished state, have captured final details: true
2016-01-15 05:07:54,435 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2
2016-01-15 05:07:54,442 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.7.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1