2015-11-23 17:08:03,489 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2015-11-23 17:08:03,505 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2015-11-23 17:08:03,517 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2015-11-23 17:08:04,105 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
2015-11-23 17:08:04,678 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(125)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2015-11-23 17:08:08,385 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.
2015-11-23 17:08:09,750 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.
2015-11-23 17:08:09,943 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.
2015-11-23 17:08:10,130 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.
2015-11-23 17:08:27,249 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2015-11-23 17:08:27,395 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2015-11-23 17:08:27,401 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /root/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.2/a7e0a109fe1f98639fc92e32694f202ce66d81a8/cascading-hadoop2-mr1-3.0.2.jar
2015-11-23 17:08:27,447 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 7E2A6FF4A4C94449A79AA944C21A838E
2015-11-23 17:08:27,565 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.085
2015-11-23 17:08:27,567 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2015-11-23 17:08:27,569 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'
2015-11-23 17:08:27,849 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /root/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.2/a7e0a109fe1f98639fc92e32694f202ce66d81a8/cascading-hadoop2-mr1-3.0.2.jar
2015-11-23 17:08:27,888 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2015-11-23 17:08:27,889 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2015-11-23 17:08:27,890 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'
2015-11-23 17:08:27,920 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.2
2015-11-23 17:08:27,920 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2015-11-23 17:08:27,928 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2015-11-23 17:08:27,929 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2015-11-23 17:08:27,929 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2015-11-23 17:08:27,930 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2015-11-23 17:08:27,931 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2015-11-23 17:08:27,931 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] at least one sink is marked for delete
2015-11-23 17:08:27,931 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] at least one sink is marked for delete
2015-11-23 17:08:27,932 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink oldest modified date: Thu Jan 01 07:59:59 CST 1970
2015-11-23 17:08:27,932 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink oldest modified date: Thu Jan 01 07:59:59 CST 1970
2015-11-23 17:08:27,970 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting
2015-11-23 17:08:27,971 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting
2015-11-23 17:08:27,971 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/classes/test/data/apache.10.txt"]
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/classes/test/data/apache.10.txt"]
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1"]
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2"]
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] parallel execution of steps is enabled: true
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] parallel execution of steps is enabled: true
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] executing total steps: 2
2015-11-23 17:08:27,973 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] allocating management threads: 2
2015-11-23 17:08:27,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] executing total steps: 2
2015-11-23 17:08:27,973 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] allocating management threads: 2
2015-11-23 17:08:27,974 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (1/2)
2015-11-23 17:08:27,977 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (1/2)
2015-11-23 17:08:28,967 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1448269701746_0002
2015-11-23 17:08:28,967 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1448269701746_0001
2015-11-23 17:08:28,967 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://shihc046-public.cn.ibm.com:54401/proxy/application_1448269701746_0001/
2015-11-23 17:08:28,967 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://shihc046-public.cn.ibm.com:54401/proxy/application_1448269701746_0002/
2015-11-23 17:08:38,218 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0001_01_000004 is : 143
2015-11-23 17:08:38,229 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0001_01_000003 is : 143
2015-11-23 17:08:38,249 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0001_01_000005 is : 143
2015-11-23 17:08:43,422 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0001_01_000006 is : 143
2015-11-23 17:08:44,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2015-11-23 17:08:44,725 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] submitted hadoop job: job_1448269701746_0003
2015-11-23 17:08:44,726 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] tracking url: http://shihc046-public.cn.ibm.com:54401/proxy/application_1448269701746_0003/
2015-11-23 17:08:58,439 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0002_01_000002 is : 143
2015-11-23 17:08:58,473 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0002_01_000005 is : 143
2015-11-23 17:08:58,512 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0002_01_000004 is : 143
2015-11-23 17:08:58,537 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0002_01_000003 is : 143
2015-11-23 17:09:03,481 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0002_01_000006 is : 143
2015-11-23 17:09:05,015 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2015-11-23 17:09:05,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] submitted hadoop job: job_1448269701746_0004
2015-11-23 17:09:05,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] tracking url: http://shihc046-public.cn.ibm.com:54401/proxy/application_1448269701746_0004/
2015-11-23 17:09:18,160 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0003_01_000002 is : 143
2015-11-23 17:09:23,304 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0003_01_000003 is : 143
2015-11-23 17:09:24,491 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2015-11-23 17:09:24,498 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] completed in: 00:56.513, using cpu time: 00:05.570
2015-11-23 17:09:24,498 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2015-11-23 17:09:37,945 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0004_01_000002 is : 143
2015-11-23 17:09:42,915 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(223)) - Exit code from container container_1448269701746_0004_01_000003 is : 143
2015-11-23 17:09:44,087 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/test/output/hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2015-11-23 17:09:44,092 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] completed in: 01:16.108, using cpu time: 00:05.790
2015-11-23 17:09:44,092 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2015-11-23 17:09:47,426 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2015-11-23 17:09:47,465 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FBD6E] retrieved task reports: 4
2015-11-23 17:09:47,468 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FBD6E] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2015-11-23 17:09:47,469 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:FBD6E] all 4 children are in finished state, have captured final details: true
2015-11-23 17:09:47,498 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D5775] retrieved task reports: 1
2015-11-23 17:09:47,500 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D5775] added 1, updated: 0 slices, with duration: 00:00.002, total fetched: 1
2015-11-23 17:09:47,500 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D5775] all 1 children are in finished state, have captured final details: true
2015-11-23 17:09:47,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:DD716] retrieved task reports: 1
2015-11-23 17:09:47,580 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:DD716] added 1, updated: 0 slices, with duration: 00:00.002, total fetched: 1
2015-11-23 17:09:47,581 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:DD716] all 1 children are in finished state, have captured final details: true
2015-11-23 17:09:47,587 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D7B47] retrieved task reports: 1
2015-11-23 17:09:47,589 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D7B47] added 1, updated: 0 slices, with duration: 00:00.002, total fetched: 1
2015-11-23 17:09:47,589 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats1 test] [node:D7B47] all 1 children are in finished state, have captured final details: true
2015-11-23 17:09:50,746 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2015-11-23 17:09:50,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D198D] retrieved task reports: 4
2015-11-23 17:09:50,756 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D198D] added 4, updated: 0 slices, with duration: 00:00.002, total fetched: 4
2015-11-23 17:09:50,756 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D198D] all 4 children are in finished state, have captured final details: true
2015-11-23 17:09:50,778 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:BE15C] retrieved task reports: 1
2015-11-23 17:09:50,779 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:BE15C] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2015-11-23 17:09:50,780 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:BE15C] all 1 children are in finished state, have captured final details: true
2015-11-23 17:09:53,926 WARN hdfs.DFSClient (DFSInputStream.java:close(669)) - DFSInputStream has been closed already
2015-11-23 17:09:53,929 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D9B58] retrieved task reports: 1
2015-11-23 17:09:53,931 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D9B58] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2015-11-23 17:09:53,932 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:D9B58] all 1 children are in finished state, have captured final details: true
2015-11-23 17:09:53,955 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:CB1BF] retrieved task reports: 1
2015-11-23 17:09:53,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:CB1BF] added 1, updated: 0 slices, with duration: 00:00.002, total fetched: 1
2015-11-23 17:09:53,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [stats2 test] [node:CB1BF] all 1 children are in finished state, have captured final details: true
2015-11-23 17:09:53,968 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats2
2015-11-23 17:09:53,975 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /root/yuanbo/cascading.compatibility-3.0/biginsights-4.1/build/test/output//hadoop2-mr1/cascadingstatsplatform/testStatsCounters/flowstats1