2016-05-18 08:38:28,965 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 08:38:28,995 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-05-18 08:38:29,025 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-18 08:38:30,044 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 08:38:30,744 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-18 08:38:35,053 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 08:38:35,263 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 08:38:35,428 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 08:38:35,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 08:38:52,690 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 08:38:52,786 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:38:52,787 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 08:38:52,853 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 871F3BCDE7854EA888C808E2CD42EEA4
2016-05-18 08:38:53,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.144
2016-05-18 08:38:53,039 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 08:38:53,040 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 08:38:53,203 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 08:38:53,389 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.175
2016-05-18 08:38:53,394 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 08:38:53,394 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 08:38:53,474 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 08:38:53,474 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-05-18 08:38:53,478 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-05-18 08:38:53,479 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-05-18 08:38:53,479 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-05-18 08:38:53,479 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-05-18 08:38:53,480 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] at least one sink is marked for delete
2016-05-18 08:38:53,480 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-05-18 08:38:53,480 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:38:53,480 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] at least one sink is marked for delete
2016-05-18 08:38:53,481 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:38:53,508 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting
2016-05-18 08:38:53,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting
2016-05-18 08:38:53,509 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.6.x/build/classes/test/data/apache.10.txt"]
2016-05-18 08:38:53,510 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.6.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-05-18 08:38:53,510 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] parallel execution of steps is enabled: true
2016-05-18 08:38:53,510 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executing total steps: 2
2016-05-18 08:38:53,510 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] allocating management threads: 2
2016-05-18 08:38:53,510 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.6.x/build/classes/test/data/apache.10.txt"]
2016-05-18 08:38:53,511 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (1/2)
2016-05-18 08:38:53,512 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.6.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-05-18 08:38:53,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] parallel execution of steps is enabled: true
2016-05-18 08:38:53,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executing total steps: 2
2016-05-18 08:38:53,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] allocating management threads: 2
2016-05-18 08:38:53,515 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (1/2)
2016-05-18 08:38:54,556 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463560727189_0001
2016-05-18 08:38:54,556 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463560727189_0002
2016-05-18 08:38:54,556 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:49396/proxy/application_1463560727189_0001/
2016-05-18 08:38:54,556 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:49396/proxy/application_1463560727189_0002/
2016-05-18 08:39:12,623 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0001_01_000003 is : 143
2016-05-18 08:39:12,962 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0001_01_000002 is : 143
2016-05-18 08:39:13,246 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0001_01_000004 is : 143
2016-05-18 08:39:13,517 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0001_01_000005 is : 143
2016-05-18 08:39:20,045 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0001_01_000006 is : 143
2016-05-18 08:39:21,226 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-05-18 08:39:21,424 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463560727189_0003
2016-05-18 08:39:21,424 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:49396/proxy/application_1463560727189_0003/
2016-05-18 08:39:43,784 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0002_01_000002 is : 143
2016-05-18 08:39:43,925 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0002_01_000004 is : 143
2016-05-18 08:39:44,121 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0002_01_000005 is : 143
2016-05-18 08:39:50,270 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0002_01_000006 is : 143
2016-05-18 08:39:51,432 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-05-18 08:39:51,566 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463560727189_0004
2016-05-18 08:39:51,566 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:49396/proxy/application_1463560727189_0004/
2016-05-18 08:40:07,910 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0003_01_000002 is : 143
2016-05-18 08:40:14,701 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0003_01_000003 is : 143
2016-05-18 08:40:15,903 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-05-18 08:40:15,905 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] completed in: 01:22.388, using cpu time: 00:09.220
2016-05-18 08:40:15,905 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-05-18 08:40:32,779 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0004_01_000002 is : 143
2016-05-18 08:40:39,703 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463560727189_0004_01_000003 is : 143
2016-05-18 08:40:40,862 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-05-18 08:40:40,864 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] completed in: 01:47.351, using cpu time: 00:08.500
2016-05-18 08:40:40,864 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-05-18 08:40:44,383 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:C666F] retrieved task reports: 4
2016-05-18 08:40:44,386 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:C666F] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-05-18 08:40:44,386 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:C666F] all 4 children are in finished state, have captured final details: true
2016-05-18 08:40:44,398 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:EBB45] retrieved task reports: 1
2016-05-18 08:40:44,399 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:EBB45] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 08:40:44,399 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:EBB45] all 1 children are in finished state, have captured final details: true
2016-05-18 08:40:47,604 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B4EB6] retrieved task reports: 1
2016-05-18 08:40:47,604 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B4EB6] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 08:40:47,604 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:B4EB6] all 1 children are in finished state, have captured final details: true
2016-05-18 08:40:47,614 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A740B] retrieved task reports: 1
2016-05-18 08:40:47,615 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A740B] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 08:40:47,615 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A740B] all 1 children are in finished state, have captured final details: true
2016-05-18 08:40:50,816 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:AE8AA] retrieved task reports: 4
2016-05-18 08:40:50,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:AE8AA] added 4, updated: 0 slices, with duration: 00:00.001, total fetched: 4
2016-05-18 08:40:50,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:AE8AA] all 4 children are in finished state, have captured final details: true
2016-05-18 08:40:50,827 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B5B0F] retrieved task reports: 1
2016-05-18 08:40:50,828 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B5B0F] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 08:40:50,828 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B5B0F] all 1 children are in finished state, have captured final details: true
2016-05-18 08:40:53,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F3DFD] retrieved task reports: 1
2016-05-18 08:40:53,969 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F3DFD] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 08:40:53,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:F3DFD] all 1 children are in finished state, have captured final details: true
2016-05-18 08:40:53,979 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:BFFAC] retrieved task reports: 1
2016-05-18 08:40:53,980 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:BFFAC] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 08:40:53,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:BFFAC] all 1 children are in finished state, have captured final details: true
2016-05-18 08:40:53,984 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2
2016-05-18 08:40:53,992 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1