2016-05-18 05:43:28,242 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 05:43:28,264 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.stats.hadoop.HadoopStatsPlatformTest, with platform: hadoop2-mr1
2016-05-18 05:43:28,295 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-18 05:43:29,174 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-05-18 05:43:29,777 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-18 05:43:30,274 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:43:33,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-05-18 05:43:33,372 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-05-18 05:43:33,485 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-05-18 05:43:33,595 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-05-18 05:43:45,423 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:43:46,422 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:43:46,423 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:43:50,671 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 05:43:50,768 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:43:50,769 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 05:43:50,834 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 5B0CA90B1FAC4A23A131EB7FC9DA379D
2016-05-18 05:43:51,016 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.142
2016-05-18 05:43:51,020 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 05:43:51,020 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:43:51,182 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:43:51,183 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 05:43:51,295 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.102
2016-05-18 05:43:51,297 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 05:43:51,297 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:43:51,348 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 05:43:51,348 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-05-18 05:43:51,354 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-05-18 05:43:51,354 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-05-18 05:43:51,354 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-05-18 05:43:51,354 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-05-18 05:43:51,354 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-05-18 05:43:51,355 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] at least one sink is marked for delete
2016-05-18 05:43:51,356 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:43:51,355 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] at least one sink is marked for delete
2016-05-18 05:43:51,357 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:43:51,383 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting
2016-05-18 05:43:51,383 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting
2016-05-18 05:43:51,383 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-05-18 05:43:51,384 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2"]
2016-05-18 05:43:51,384 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] parallel execution of steps is enabled: true
2016-05-18 05:43:51,384 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executing total steps: 2
2016-05-18 05:43:51,384 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] allocating management threads: 2
2016-05-18 05:43:51,383 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-05-18 05:43:51,387 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1"]
2016-05-18 05:43:51,387 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (1/2)
2016-05-18 05:43:51,387 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] parallel execution of steps is enabled: true
2016-05-18 05:43:51,388 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executing total steps: 2
2016-05-18 05:43:51,388 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] allocating management threads: 2
2016-05-18 05:43:51,392 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (1/2)
2016-05-18 05:43:52,215 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463550225169_0001
2016-05-18 05:43:52,215 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:54925/proxy/application_1463550225169_0001/
2016-05-18 05:43:52,386 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463550225169_0002
2016-05-18 05:43:52,386 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:54925/proxy/application_1463550225169_0002/
2016-05-18 05:44:19,175 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0001_01_000002 is : 143
2016-05-18 05:44:19,371 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0001_01_000003 is : 143
2016-05-18 05:44:20,750 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0001_01_000004 is : 143
2016-05-18 05:44:22,137 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0002_01_000002 is : 143
2016-05-18 05:44:22,566 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0002_01_000003 is : 143
2016-05-18 05:44:22,650 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0002_01_000004 is : 143
2016-05-18 05:44:27,145 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0001_01_000006 is : 143
2016-05-18 05:44:28,543 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-05-18 05:44:28,957 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463550225169_0003
2016-05-18 05:44:28,957 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:54925/proxy/application_1463550225169_0003/
2016-05-18 05:44:30,575 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0002_01_000006 is : 143
2016-05-18 05:44:31,764 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-05-18 05:44:31,925 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463550225169_0004
2016-05-18 05:44:31,925 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:54925/proxy/application_1463550225169_0004/
2016-05-18 05:44:47,007 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0003_01_000002 is : 143
2016-05-18 05:44:51,347 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0004_01_000002 is : 143
2016-05-18 05:44:54,078 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0003_01_000003 is : 143
2016-05-18 05:44:55,341 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2/_temporary
2016-05-18 05:44:55,343 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] completed in: 01:03.952, using cpu time: 00:08.940
2016-05-18 05:44:55,344 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-05-18 05:44:58,307 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550225169_0004_01_000003 is : 143
2016-05-18 05:44:59,596 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1/_temporary
2016-05-18 05:44:59,598 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] completed in: 01:08.207, using cpu time: 00:08.430
2016-05-18 05:44:59,598 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-05-18 05:45:03,136 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:E7430] retrieved task reports: 4
2016-05-18 05:45:03,139 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:E7430] added 4, updated: 0 slices, with duration: 00:00.002, total fetched: 4
2016-05-18 05:45:03,140 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:E7430] all 4 children are in finished state, have captured final details: true
2016-05-18 05:45:03,152 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:E0B82] retrieved task reports: 1
2016-05-18 05:45:03,153 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:E0B82] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 05:45:03,153 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:E0B82] all 1 children are in finished state, have captured final details: true
2016-05-18 05:45:03,363 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A8F19] retrieved task reports: 1
2016-05-18 05:45:03,364 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A8F19] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 05:45:03,364 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A8F19] all 1 children are in finished state, have captured final details: true
2016-05-18 05:45:03,378 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B4EDC] retrieved task reports: 1
2016-05-18 05:45:03,379 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B4EDC] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:45:03,379 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B4EDC] all 1 children are in finished state, have captured final details: true
2016-05-18 05:45:06,577 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:E32BE] retrieved task reports: 4
2016-05-18 05:45:06,579 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:E32BE] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-05-18 05:45:06,580 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:E32BE] all 4 children are in finished state, have captured final details: true
2016-05-18 05:45:06,589 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A9F7A] retrieved task reports: 1
2016-05-18 05:45:06,590 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A9F7A] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:45:06,591 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A9F7A] all 1 children are in finished state, have captured final details: true
2016-05-18 05:45:06,727 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:C18E4] retrieved task reports: 1
2016-05-18 05:45:06,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:C18E4] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:45:06,729 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:C18E4] all 1 children are in finished state, have captured final details: true
2016-05-18 05:45:06,737 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:D6848] retrieved task reports: 1
2016-05-18 05:45:06,738 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:D6848] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 05:45:06,738 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:D6848] all 1 children are in finished state, have captured final details: true
2016-05-18 05:45:06,743 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats1
2016-05-18 05:45:06,751 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/hadoopstatsplatform/testStatsCounters/flowstats2