2016-05-18 05:41:48,863 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 05:41:48,883 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.stats.CascadingStatsPlatformTest, with platform: hadoop2-mr1
2016-05-18 05:41:48,905 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-18 05:41:49,636 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:41:50,277 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-18 05:41:50,835 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:41:54,004 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:41:54,155 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:41:54,271 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:41:54,385 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:42:06,252 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:42:07,228 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:42:07,228 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(166)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 05:42:11,466 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 05:42:11,570 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:42:11,571 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:42:11,640 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: E2BAC237926949ADB7599061F0C80748
2016-05-18 05:42:11,812 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.134
2016-05-18 05:42:11,815 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 05:42:11,816 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:42:11,962 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:42:12,048 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.079
2016-05-18 05:42:12,050 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 05:42:12,050 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:42:12,095 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 05:42:12,095 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting
2016-05-18 05:42:12,099 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] parallel execution of flows is enabled: true
2016-05-18 05:42:12,099 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] executing total flows: 2
2016-05-18 05:42:12,099 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] allocating management threads: 2
2016-05-18 05:42:12,100 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats1 test
2016-05-18 05:42:12,100 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] at least one sink is marked for delete
2016-05-18 05:42:12,101 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:42:12,100 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] starting flow: stats2 test
2016-05-18 05:42:12,102 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] at least one sink is marked for delete
2016-05-18 05:42:12,102 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:42:12,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting
2016-05-18 05:42:12,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting
2016-05-18 05:42:12,123 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:42:12,123 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:42:12,123 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/cascadingstatsplatform/testStatsCounters/flowstats1"]
2016-05-18 05:42:12,123 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/cascadingstatsplatform/testStatsCounters/flowstats2"]
2016-05-18 05:42:12,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] parallel execution of steps is enabled: true
2016-05-18 05:42:12,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] parallel execution of steps is enabled: true
2016-05-18 05:42:12,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] executing total steps: 2
2016-05-18 05:42:12,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] executing total steps: 2
2016-05-18 05:42:12,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] allocating management threads: 2
2016-05-18 05:42:12,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] allocating management threads: 2
2016-05-18 05:42:12,126 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (1/2)
2016-05-18 05:42:12,126 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (1/2)
2016-05-18 05:42:13,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463550125964_0001
2016-05-18 05:42:13,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:45508/proxy/application_1463550125964_0001/
2016-05-18 05:42:13,136 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463550125964_0002
2016-05-18 05:42:13,136 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:45508/proxy/application_1463550125964_0002/
2016-05-18 05:42:39,846 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0001_01_000002 is : 143
2016-05-18 05:42:40,387 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0001_01_000003 is : 143
2016-05-18 05:42:41,530 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0001_01_000004 is : 143
2016-05-18 05:42:41,664 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0001_01_000005 is : 143
2016-05-18 05:42:42,674 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0002_01_000003 is : 143
2016-05-18 05:42:42,797 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0002_01_000005 is : 143
2016-05-18 05:42:43,037 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0002_01_000004 is : 143
2016-05-18 05:42:43,144 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0002_01_000002 is : 143
2016-05-18 05:42:47,948 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0001_01_000006 is : 143
2016-05-18 05:42:49,309 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] starting step: (2/2) ...tStatsCounters/flowstats1
2016-05-18 05:42:49,695 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] submitted hadoop job: job_1463550125964_0003
2016-05-18 05:42:49,695 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] tracking url: http://ip-10-158-37-203:45508/proxy/application_1463550125964_0003/
2016-05-18 05:42:51,299 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0002_01_000006 is : 143
2016-05-18 05:42:52,493 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] starting step: (2/2) ...tStatsCounters/flowstats2
2016-05-18 05:42:52,699 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] submitted hadoop job: job_1463550125964_0004
2016-05-18 05:42:52,699 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] tracking url: http://ip-10-158-37-203:45508/proxy/application_1463550125964_0004/
2016-05-18 05:43:08,064 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0003_01_000002 is : 143
2016-05-18 05:43:10,454 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0004_01_000002 is : 143
2016-05-18 05:43:16,007 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0003_01_000003 is : 143
2016-05-18 05:43:17,379 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/cascadingstatsplatform/testStatsCounters/flowstats1/_temporary
2016-05-18 05:43:17,380 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] completed in: 01:05.248, using cpu time: 00:09.470
2016-05-18 05:43:17,381 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats1 test
2016-05-18 05:43:18,496 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463550125964_0004_01_000003 is : 143
2016-05-18 05:43:19,768 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/cascadingstatsplatform/testStatsCounters/flowstats2/_temporary
2016-05-18 05:43:19,770 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] completed in: 01:07.642, using cpu time: 00:08.250
2016-05-18 05:43:19,770 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [stats1 test+stats2 test] completed flow: stats2 test
2016-05-18 05:43:23,296 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:FA854] retrieved task reports: 4
2016-05-18 05:43:23,299 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:FA854] added 4, updated: 0 slices, with duration: 00:00.003, total fetched: 4
2016-05-18 05:43:23,299 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:FA854] all 4 children are in finished state, have captured final details: true
2016-05-18 05:43:23,311 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A1FC3] retrieved task reports: 1
2016-05-18 05:43:23,312 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A1FC3] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:43:23,312 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:A1FC3] all 1 children are in finished state, have captured final details: true
2016-05-18 05:43:23,362 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:BB4BD] retrieved task reports: 1
2016-05-18 05:43:23,363 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:BB4BD] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:43:23,364 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:BB4BD] all 1 children are in finished state, have captured final details: true
2016-05-18 05:43:23,369 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:DB09D] retrieved task reports: 1
2016-05-18 05:43:23,370 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:DB09D] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 05:43:23,370 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats2 test] [node:DB09D] all 1 children are in finished state, have captured final details: true
2016-05-18 05:43:26,576 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A4B48] retrieved task reports: 4
2016-05-18 05:43:26,577 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A4B48] added 4, updated: 0 slices, with duration: 00:00.000, total fetched: 4
2016-05-18 05:43:26,578 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A4B48] all 4 children are in finished state, have captured final details: true
2016-05-18 05:43:26,590 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B0272] retrieved task reports: 1
2016-05-18 05:43:26,590 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B0272] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:43:26,590 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B0272] all 1 children are in finished state, have captured final details: true
2016-05-18 05:43:26,746 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A31C8] retrieved task reports: 1
2016-05-18 05:43:26,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A31C8] added 1, updated: 0 slices, with duration: 00:00.000, total fetched: 1
2016-05-18 05:43:26,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:A31C8] all 1 children are in finished state, have captured final details: true
2016-05-18 05:43:26,756 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B2307] retrieved task reports: 1
2016-05-18 05:43:26,757 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B2307] added 1, updated: 0 slices, with duration: 00:00.001, total fetched: 1
2016-05-18 05:43:26,757 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [stats1 test] [node:B2307] all 1 children are in finished state, have captured final details: true
2016-05-18 05:43:26,761 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/cascadingstatsplatform/testStatsCounters/flowstats2
2016-05-18 05:43:26,768 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/cascadingstatsplatform/testStatsCounters/flowstats1