2016-05-18 11:46:54,336 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 11:46:54,359 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-05-18 11:46:54,381 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-18 11:46:55,516 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 11:46:56,129 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(125)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-18 11:47:00,512 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-05-18 11:47:00,726 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-05-18 11:47:00,907 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-05-18 11:47:01,087 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-05-18 11:47:19,702 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 11:47:19,834 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:47:19,835 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 11:47:19,899 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 790C8CD19E25472A996BF488C271C3B4
2016-05-18 11:47:20,085 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.144
2016-05-18 11:47:20,088 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 11:47:20,089 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 11:47:20,251 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 11:47:20,368 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.108
2016-05-18 11:47:20,371 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 11:47:20,371 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 11:47:20,420 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 11:47:20,421 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-05-18 11:47:20,425 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-05-18 11:47:20,425 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-05-18 11:47:20,425 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-05-18 11:47:20,426 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-05-18 11:47:20,426 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] at least one sink is marked for delete
2016-05-18 11:47:20,427 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-05-18 11:47:20,428 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] at least one sink is marked for delete
2016-05-18 11:47:20,428 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 11:47:20,427 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 11:47:20,453 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting
2016-05-18 11:47:20,453 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting
2016-05-18 11:47:20,454 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.7.x/build/classes/test/data/apache.10.txt"]
2016-05-18 11:47:20,454 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.7.x/build/classes/test/data/apache.10.txt"]
2016-05-18 11:47:20,454 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.7.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-05-18 11:47:20,454 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.7.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-05-18 11:47:20,454 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] parallel execution of steps is enabled: true
2016-05-18 11:47:20,455 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executing total steps: 2
2016-05-18 11:47:20,455 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] allocating management threads: 2
2016-05-18 11:47:20,454 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] parallel execution of steps is enabled: true
2016-05-18 11:47:20,455 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executing total steps: 2
2016-05-18 11:47:20,457 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] allocating management threads: 2
2016-05-18 11:47:20,457 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (1/2)
2016-05-18 11:47:20,460 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (1/2)
2016-05-18 11:47:21,340 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463572034200_0001
2016-05-18 11:47:21,341 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:41468/proxy/application_1463572034200_0001/
2016-05-18 11:47:21,500 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463572034200_0002
2016-05-18 11:47:21,500 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:41468/proxy/application_1463572034200_0002/
2016-05-18 11:47:40,121 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0001_01_000002 is : 143
2016-05-18 11:47:40,492 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0001_01_000003 is : 143
2016-05-18 11:47:40,865 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0001_01_000004 is : 143
2016-05-18 11:47:40,994 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0001_01_000005 is : 143
2016-05-18 11:47:47,017 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0001_01_000006 is : 143
2016-05-18 11:47:48,222 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-05-18 11:47:48,413 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463572034200_0003
2016-05-18 11:47:48,413 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:41468/proxy/application_1463572034200_0003/
2016-05-18 11:48:12,481 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0002_01_000002 is : 143
2016-05-18 11:48:12,554 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0002_01_000003 is : 143
2016-05-18 11:48:12,850 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0002_01_000005 is : 143
2016-05-18 11:48:13,015 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0002_01_000004 is : 143
2016-05-18 11:48:20,364 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0002_01_000006 is : 143
2016-05-18 11:48:21,506 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-05-18 11:48:21,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463572034200_0004
2016-05-18 11:48:21,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:41468/proxy/application_1463572034200_0004/
2016-05-18 11:48:39,753 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0003_01_000002 is : 143
2016-05-18 11:48:46,681 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0003_01_000003 is : 143
2016-05-18 11:48:47,877 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-05-18 11:48:47,879 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] completed in: 01:27.417, using cpu time: 00:08.060
2016-05-18 11:48:47,880 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-05-18 11:49:05,397 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0004_01_000002 is : 143
2016-05-18 11:49:12,642 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463572034200_0004_01_000003 is : 143
2016-05-18 11:49:13,841 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-05-18 11:49:13,843 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] completed in: 01:53.387, using cpu time: 00:08.490
2016-05-18 11:49:13,843 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-05-18 11:49:17,248 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:C7852] retrieved task reports: 4
2016-05-18 11:49:17,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:C7852] added 4, updated: 0 slices, with duration: 00:00.002, total fetched: 4
2016-05-18 11:49:17,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:C7852] all 4 children are in finished state, have captured final details: true
2016-05-18 11:49:17,264 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:F5DB9] retrieved task reports: 1
2016-05-18 11:49:17,265 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:F5DB9] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 11:49:17,265 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:F5DB9] all 1 children are in finished state, have captured final details: true
2016-05-18 11:49:20,485 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B75D0] retrieved task reports: 1
2016-05-18 11:49:20,486 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B75D0] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 11:49:20,487 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B75D0] all 1 children are in finished state, have captured final details: true
2016-05-18 11:49:20,497 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:BF9A6] retrieved task reports: 1
2016-05-18 11:49:20,497 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:BF9A6] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 11:49:20,497 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:BF9A6] all 1 children are in finished state, have captured final details: true
2016-05-18 11:49:23,706 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:D160F] retrieved task reports: 4
2016-05-18 11:49:23,707 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:D160F] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-05-18 11:49:23,707 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:D160F] all 4 children are in finished state, have captured final details: true
2016-05-18 11:49:23,719 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A00C0] retrieved task reports: 1
2016-05-18 11:49:23,719 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A00C0] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 11:49:23,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A00C0] all 1 children are in finished state, have captured final details: true
2016-05-18 11:49:23,860 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:DE93F] retrieved task reports: 1
2016-05-18 11:49:23,861 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:DE93F] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 11:49:23,861 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:DE93F] all 1 children are in finished state, have captured final details: true
2016-05-18 11:49:23,870 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B6B90] retrieved task reports: 1
2016-05-18 11:49:23,872 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B6B90] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 11:49:23,872 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B6B90] all 1 children are in finished state, have captured final details: true
2016-05-18 11:49:23,875 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1
2016-05-18 11:49:23,882 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2