2016-05-17 21:34:41,067 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-17 21:34:41,086 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.tap.hadoop.HadoopTapPlatformTest, with platform: hadoop2-tez
2016-05-17 21:34:41,118 INFO tez.Hadoop2TezPlatform (Hadoop2TezPlatform.java:setUp(164)) - using cluster
2016-05-17 21:34:41,722 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-17 21:34:42,579 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-17 21:34:43,092 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-17 21:34:45,640 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(109)) - Using Tez AppJar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-dag/0.6.2/7cfbec38ae59bd135b5606c0b42dce12b41c076c/tez-dag-0.6.2.jar
2016-05-17 21:34:45,851 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(121)) - Set TEZ-LIB-URI to: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:34:45,857 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(152)) - mkdir: hdfs://localhost:34374/apps_staging_dir
2016-05-17 21:34:46,198 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - 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-17 21:34:46,326 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - 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-17 21:34:46,373 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - 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-17 21:34:46,422 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - 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-17 21:34:46,427 INFO test.MiniTezCluster (MiniTezCluster.java:serviceStart(186)) - Starting MiniTezCluster
2016-05-17 21:34:52,060 INFO test.MiniTezCluster (MiniTezCluster.java:serviceStart(205)) - Setting yarn-site.xml via YARN-APP-CP at: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/target/cascading.platform.tez.Hadoop2TezPlatform,/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/resources/test:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/main:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/resources/main:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-core/3.1.0/9f41bc3c02048b244161c34aab73acda810c2389/cascading-core-3.1.0-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-platform/3.1.0/38cd2eba8dbbc1efc3f097f196965a60c99cbf2f/cascading-platform-3.1.0-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/11d23daa35c4c17d09d6a8d13b7964dbabd56bf6/cascading-hadoop2-tez-3.1.0-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez-stats/3.1.0/2b8a4fba885da289dd195ea1f6840a76b16f77a6/cascading-hadoop2-tez-stats-3.1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-io/3.1.0/32191afb3963b6ad8992408fd1432cd213fd8de6/cascading-hadoop2-io-3.1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-core/2.4.1/4b563f928dc108bfc9974e2c643e275bbb407625/hadoop-mapreduce-client-core-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-common/2.4.1/5e9d624fb9eeab4b1a940f5e9b1c9ff644ec1d65/hadoop-common-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-minicluster/2.4.1/8cddcdc0c553483c635909b2029cff67d19e138c/hadoop-minicluster-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-api/1.7.5/6b262da268f8ad9eff941b25503a9198f0a0ac93/slf4j-api-1.7.5.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-log4j12/1.7.5/6edffc576ce104ec769d954618764f39f0f0f10d/slf4j-log4j12-1.7.5.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-tests/0.6.2/e6c7cbbf7f067cea6a8f8c5bea595536e141dd70/tez-tests-0.6.2-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-api/0.6.2/7be44271b408cb2a59181fc1c3d45d0bb2e6bb93/tez-api-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-dag/0.6.2/7cfbec38ae59bd135b5606c0b42dce12b41c076c/tez-dag-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-yarn-timeline-history/0.6.2/4765a7b7c177208970def6b9640c1366a61c264c/tez-yarn-timeline-history-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/junit/junit/4.12/2973d150c0dc1fefe998f834810d68f278ea58ec/junit-4.12.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/riffle/riffle/1.0.0/d991264d10c1e80f8588d2480e3f6e536e30fcb2/riffle-1.0.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.jgrapht/jgrapht-core/0.9.2/2597c1f9aa80fcfdd1f2e8ad0f0655bd768d95ca/jgrapht-core-0.9.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-core/3.1.0/ba7756e455a94ae4c9cf9a2debeb7085e46f05e5/cascading-core-3.1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-expression/3.1.0/47daa0fd74a26bfe727c2e6c06f8b9c7e9cb91c3/cascading-expression-3.1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-common/2.4.1/5079e4fb2bf12dff172ccceefc812f29c3295168/hadoop-yarn-common-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.google.protobuf/protobuf-java/2.5.0/a10732c76bfacdbd633a7eb0f7968b1059a65dfa/protobuf-java-2.5.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.avro/avro/1.7.4/416e7030879814f52845b97f04bb50ecd1cef372/avro-1.7.4.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-annotations/2.4.1/80434aa40184be711d1c41568852fee625925ab0/hadoop-annotations-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.google.inject.extensions/guice-servlet/3.0/610cde0e8da5a8b7d8efb8f0b8987466ffebaaf9/guice-servlet-3.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/io.netty/netty/3.6.2.Final/69be11c61427f0604a30539755add84ad9e37e5e/netty-3.6.2.Final.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.google.guava/guava/11.0.2/35a3c69e19d72743cac83778aecbee68680f63eb/guava-11.0.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-cli/commons-cli/1.2/2bf96b7aa8b611c177d329452af1dc933e14501c/commons-cli-1.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.commons/commons-math3/3.1.1/6719d757a98ff24a83d9d727bef9cec83f59b6e1/commons-math3-3.1.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/xmlenc/xmlenc/0.52/d82554efbe65906d83b3d97bd7509289e9db561a/xmlenc-0.52.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-httpclient/commons-httpclient/3.1/964cd74171f427720480efdec40a7c7f6e58426a/commons-httpclient-3.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-io/commons-io/2.4/b1b6ea3b7e4aa4f492509a4952029cd8e48019ad/commons-io-2.4.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-net/commons-net/3.1/2298164a7c2484406f2aa5ac85b205d39019896f/commons-net-3.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-collections/commons-collections/3.2.1/761ea405b9b37ced573d2df0d1e3a4e0f9edc668/commons-collections-3.2.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/javax.servlet/servlet-api/2.5/5959582d97d8b61f4d154ca9e495aafd16726e34/servlet-api-2.5.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.mortbay.jetty/jetty/6.1.26/2f546e289fddd5b1fab1d4199fbb6e9ef43ee4b0/jetty-6.1.26.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.mortbay.jetty/jetty-util/6.1.26/e5642fe0399814e1687d55a3862aa5a3417226a9/jetty-util-6.1.26.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.sun.jersey/jersey-core/1.9/8341846f18187013bb9e27e46b7ee00a6395daf4/jersey-core-1.9.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.sun.jersey/jersey-json/1.9/1aa73e1896bcc7013fed247157d7f676226eb432/jersey-json-1.9.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.sun.jersey/jersey-server/1.9/3a6ea7cc5e15c824953f9f3ece2201b634d90d18/jersey-server-1.9.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/tomcat/jasper-compiler/5.5.23/6d35bd7fb8c4fbc1f5401fb3678aa976d2e4c241/jasper-compiler-5.5.23.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/tomcat/jasper-runtime/5.5.23/96ca5528a93ab47b001476b74320c644beb89dde/jasper-runtime-5.5.23.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/javax.servlet.jsp/jsp-api/2.1/63f943103f250ef1f3a4d5e94d145a0f961f5316/jsp-api-2.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-el/commons-el/1.0/1df2c042b3f2de0124750241ac6c886dbfa2cc2c/commons-el-1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-logging/commons-logging/1.1.3/f6f66e966c70a83ffbdb6f17a0919eaf7c8aca7f/commons-logging-1.1.3.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/log4j/log4j/1.2.17/5af35056b4d257e4b64b9e8069c0746e8b08629f/log4j-1.2.17.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/net.java.dev.jets3t/jets3t/0.9.0/792bc96ee7e57b89f472aa0cb5a31015b9f59c96/jets3t-0.9.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-lang/commons-lang/2.6/ce1edb914c94ebc388f086c6827e8bdeec71ac2/commons-lang-2.6.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-configuration/commons-configuration/1.6/32cadde23955d7681b0d94a2715846d20b425235/commons-configuration-1.6.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.jackson/jackson-core-asl/1.8.8/dd2e90bb710ea3bc4610e24299d6a4c8dac5049b/jackson-core-asl-1.8.8.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.jackson/jackson-mapper-asl/1.8.8/1bb32d9d2527c083a56e234acca49a48d3c65c8/jackson-mapper-asl-1.8.8.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-auth/2.4.1/96af98a34a335c5a8f2c9e40c6df57308060b1b1/hadoop-auth-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.jcraft/jsch/0.1.42/a86104b0f2e0c0bab5b0df836065823a99b5e334/jsch-0.1.42.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.zookeeper/zookeeper/3.4.5/c0f69fb36526552a8f0bc548a6c33c49cf08e562/zookeeper-3.4.5.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.commons/commons-compress/1.4.1/b02e84a993d88568417536240e970c4b809126fd/commons-compress-1.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-common/2.4.1/4b70adc7e361d45eaa046c8e4b0f34b592ba99d5/hadoop-common-2.4.1-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-hdfs/2.4.1/622cd765cf1bf31f04557f106e319814fc54a57f/hadoop-hdfs-2.4.1-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-hdfs/2.4.1/e1a4a1d3554a1779cf69332f7aa04963237d74fb/hadoop-hdfs-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-server-tests/2.4.1/e64fdb80075b00d491748b659b69845aad81762f/hadoop-yarn-server-tests-2.4.1-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-jobclient/2.4.1/c6d5f19d3ec9dc999fc5c795a5fbcc6d7487042c/hadoop-mapreduce-client-jobclient-2.4.1-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-jobclient/2.4.1/b4332fcbbe1b82c1e3adb565a34704b9101973e8/hadoop-mapreduce-client-jobclient-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-app/2.4.1/96da79f9773e0a23803e0894878c74324fe066e4/hadoop-mapreduce-client-app-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-api/2.4.1/d9ae8871a77f0da42fadd0272aad29c19ae2d800/hadoop-yarn-api-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-hs/2.4.1/eb6ff67c7177e69128a43482f493676ef6df722b/hadoop-mapreduce-client-hs-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-runtime-library/0.6.2/51f93c866043ed03d16e9657c292858b752100ad/tez-runtime-library-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-mapreduce/0.6.2/dc9fc549fb8023221647d410b3e17b751a1b2c03/tez-mapreduce-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-examples/0.6.2/cd9c5d801f5ffee25bc6e2f0a271e32c5c95c65/tez-examples-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-client/2.4.1/6d585dc8b9e3656a7fbee2ea24f80888c399f0b3/hadoop-yarn-client-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-common/2.4.1/521dc4a0796a80ebd88c661afdb0820e01f365f/hadoop-mapreduce-client-common-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.commons/commons-collections4/4.0/da217367fd25e88df52ba79e47658d4cf928b0d1/commons-collections4-4.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.sun.jersey/jersey-client/1.9/d3c4b2b5f89db32c96ceddcb863684821910a7bb/jersey-client-1.9.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-common/0.6.2/2b6e194f37e7a9931e8f2f732fd167c20395adb5/tez-common-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.tez/tez-runtime-internals/0.6.2/c03a09ad12e31ea93c2a2131fbf96f0993875e24/tez-runtime-internals-0.6.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-server-web-proxy/2.4.1/5f4efb0f7e31fbf73337773396358c8f1435ca9b/hadoop-yarn-server-web-proxy-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.jettison/jettison/1.3.4/3c08d8f699432e23023080cdc8b4073132473dc8/jettison-1.3.4.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.hamcrest/hamcrest-core/1.3/42a25dc3219429f0e5d060061f71acb49bf010a0/hamcrest-core-1.3.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.janino/janino/2.7.6/37fde5de7edd5d7ebe075f03f4c083df2ac73dd8/janino-2.7.6.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/javax.xml.bind/jaxb-api/2.2.2/aeb3021ca93dde265796d82015beecdcff95bf09/jaxb-api-2.2.2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.google.inject/guice/3.0/9d84f15fe35e2c716a02979fb62f50a29f38aefa/guice-3.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.sun.jersey.contribs/jersey-guice/1.9/5963c28c47df7e5d6ad34cec80c071c368777f7b/jersey-guice-1.9.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.thoughtworks.paranamer/paranamer/2.3/4a85963a752c0a2f715c3924bfc686865e7e1bc6/paranamer-2.3.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.xerial.snappy/snappy-java/1.0.4.1/f88b89a5a21a466aeb0ecf0c063605bd584b4947/snappy-java-1.0.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.mortbay.jetty/servlet-api/2.5-20081211/22bff70037e1e6fa7e6413149489552ee2064702/servlet-api-2.5-20081211.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.sun.xml.bind/jaxb-impl/2.2.3-1/56baae106392040a45a06d4a41099173425da1e6/jaxb-impl-2.2.3-1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.jackson/jackson-jaxrs/1.8.3/3604ca9f572170e2ef5813141ec1f0e0100efd19/jackson-jaxrs-1.8.3.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.jackson/jackson-xc/1.8.3/1226667dcdb7c259b3ee07e112ed83446554516e/jackson-xc-1.8.3.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/asm/asm/3.1/c157def142714c544bdea2e6144645702adf7097/asm-3.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.jamesmurty.utils/java-xmlbuilder/0.4/ac5962e48cdee3a0a6e1f8e00fcb594747ac5aaf/java-xmlbuilder-0.4.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-digester/commons-digester/1.8/dc6a73fdbd1fa3f0944e8497c6c872fa21dca37e/commons-digester-1.8.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-beanutils/commons-beanutils-core/1.8.0/175dc721f87e4bc5cc0573f990e28c3cf9117508/commons-beanutils-core-1.8.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.tukaani/xz/1.0/ecff5cb8b1189514c9d1d8d68eb77ac372e000c9/xz-1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-daemon/commons-daemon/1.0.13/750856a1fdb3ddf721ccf73c3518e4211cffc3a3/commons-daemon-1.0.13.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-server-common/2.4.1/3843d9ab1c871d93f691fcc15d3e3e7e2e1d6178/hadoop-yarn-server-common-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-server-nodemanager/2.4.1/17324cfa4d679e7c1113dc37dd53a5fc3e51375c/hadoop-yarn-server-nodemanager-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-server-resourcemanager/2.4.1/f0e3d23e8afa3008ab8a4ccba19fd075a052ce80/hadoop-yarn-server-resourcemanager-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-mapreduce-client-shuffle/2.4.1/36ec630ddc0748efaeefaa146a8a210ff6693225/hadoop-mapreduce-client-shuffle-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.codehaus.janino/commons-compiler/2.7.6/b71e76d942b33dfa26e4e3047ff2a774d1f917b4/commons-compiler-2.7.6.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/javax.xml.stream/stax-api/1.0-2/d6337b0de8b25e53e81b922352fbea9f9f57ba0b/stax-api-1.0-2.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/javax.activation/activation/1.1/e6cb541461c2834bdea3eb920f1884d1eb508b50/activation-1.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/javax.inject/javax.inject/1/6975da39a7040257bd51d21a231b76c915872d38/javax.inject-1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/aopalliance/aopalliance/1.0/235ba8b489512805ac13a8f9ea77a1ca5ebe3e8/aopalliance-1.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.sonatype.sisu.inject/cglib/2.2.1-v20090111/7ce5e983fd0e6c78346f4c9cbfa39d83049dda2/cglib-2.2.1-v20090111.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-beanutils/commons-beanutils/1.7.0/5675fd96b29656504b86029551973d60fb41339b/commons-beanutils-1.7.0.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.hadoop/hadoop-yarn-server-applicationhistoryservice/2.4.1/5da5194d7dd07b1335128b9292a1d044572cbb64/hadoop-yarn-server-applicationhistoryservice-2.4.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/jline/jline/0.9.94/99a18e9a44834afdebc467294e1138364c207402/jline-0.9.94.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.fusesource.leveldbjni/leveldbjni-all/1.8/707350a2eeb1fa2ed77a32ddb3893ed308e941db/leveldbjni-all-1.8.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/com.google.code.findbugs/jsr305/2.0.3/5871fb60dc68d67da54a663c3fd636a10a532948/jsr305-2.0.3.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/stax/stax-api/1.0.1/49c100caf72d658aca8e58bd74a4ba90fa2b0d70/stax-api-1.0.1.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.httpcomponents/httpclient/4.2.5/666e26e76f2e87d84e4f16acb546481ae1b8e9a6/httpclient-4.2.5.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/org.apache.httpcomponents/httpcore/4.2.4/3b7f38df6de5dd8b500e602ae8c2dd5ee446f883/httpcore-4.2.4.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/commons-codec/commons-codec/1.6/b7f0fc8f61ecadeb3695f0b9464755eee44374d4/commons-codec-1.6.jar
2016-05-17 21:34:52,468 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-17 21:34:52,608 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:34:52,609 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:34:52,679 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: BB5240823D5E416B985FD8C14E32E4D1
2016-05-17 21:34:52,797 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-05-17 21:34:52,811 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.068
2016-05-17 21:34:52,812 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:34:52,812 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:34:52,813 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:34:53,022 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/BFD8E1DB02CC453FB67110F6A5C0734C/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:34:53,082 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-17 21:34:53,083 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:34:53,084 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["CommentScheme[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/comments+lower.txt"]
2016-05-17 21:34:53,084 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNullsFromScheme/testnulls"]
2016-05-17 21:34:53,084 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:34:53,085 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:34:53,085 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:34:53,086 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...NullsFromScheme/testnulls
2016-05-17 21:34:53,102 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tez session mode enabled: false
2016-05-17 21:34:53,119 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:34:53,211 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:34:53,244 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0001
2016-05-17 21:34:53,246 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:34:53,264 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/BFD8E1DB02CC453FB67110F6A5C0734C/FF219ECD5613459F919F991FCDFC0FAA/.tez/application_1463520886428_0001 doesn't exist and is created
2016-05-17 21:34:53,431 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0001, dagName=[BFD8E1DB02CC453FB67110F6A5C0734C/FF219ECD5613459F919F991FCDFC0FAA] test/(1/1) ...NullsFromScheme/testnulls
2016-05-17 21:34:53,709 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0001/
2016-05-17 21:34:53,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted tez dag to app master: application_1463520886428_0001, with dag id: dag_1463520886428_0001_1
2016-05-17 21:35:07,181 INFO client.TimelineReaderFactory (TimelineReaderFactory.java:tokenDelegationSupported(381)) - Could not find class required for token delegation, will fallback to pseudo auth
2016-05-17 21:35:07,213 INFO counters.Limits (Limits.java:ensureInitialized(59)) - Counter limits initialized with parameters: GROUP_NAME_MAX=128, MAX_GROUPS=500, COUNTER_NAME_MAX=64, MAX_COUNTERS=1200
2016-05-17 21:35:07,221 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNullsFromScheme/testnulls/_temporary
2016-05-17 21:35:07,223 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:14.131, using cpu time: 00:03.080
2016-05-17 21:35:07,365 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testNullsFromScheme/testnulls
2016-05-17 21:35:07,434 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:35:07,434 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:07,528 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.063
2016-05-17 21:35:07,548 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.083
2016-05-17 21:35:07,549 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:35:07,549 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:35:07,550 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:35:07,594 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testMissingInputFormat/missinginputformat
2016-05-17 21:35:07,834 INFO hadoop.Hfs (Hfs.java:makeLocal(445)) - forcing job to stand-alone mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/upper.txt"]
2016-05-17 21:35:07,904 INFO hadoop.Hfs (Hfs.java:makeLocal(445)) - forcing job to stand-alone mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-05-17 21:35:08,002 INFO hadoop.Hfs (Hfs.java:makeLocal(445)) - forcing job to stand-alone mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-05-17 21:35:08,047 INFO hadoop.Hfs (Hfs.java:makeLocal(445)) - forcing job to stand-alone mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/upper.txt"]
2016-05-17 21:35:08,105 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:35:08,106 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:08,179 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-17 21:35:08,182 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.038
2016-05-17 21:35:08,183 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:08,184 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:08,184 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:35:08,226 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/752839B3F7BB430A8E8782EF97AF1CAB/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:08,257 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:35:08,257 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-05-17 21:35:08,257 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["ResolvedScheme[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testResolvedSinkFields/resolvedfields"]
2016-05-17 21:35:08,258 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:35:08,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:35:08,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:35:08,260 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...SinkFields/resolvedfields
2016-05-17 21:35:08,275 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tez session mode enabled: false
2016-05-17 21:35:08,279 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:35:08,293 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:35:08,294 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0002
2016-05-17 21:35:08,294 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:35:08,308 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/752839B3F7BB430A8E8782EF97AF1CAB/C2C602F4237E426D9A690AC858D8C2EC/.tez/application_1463520886428_0002 doesn't exist and is created
2016-05-17 21:35:08,382 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0002, dagName=[752839B3F7BB430A8E8782EF97AF1CAB/C2C602F4237E426D9A690AC858D8C2EC] test/(1/1) ...SinkFields/resolvedfields
2016-05-17 21:35:08,387 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0002/
2016-05-17 21:35:08,401 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted tez dag to app master: application_1463520886428_0002, with dag id: dag_1463520886428_0002_1
2016-05-17 21:35:12,217 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0001_01_000002 is : 143
2016-05-17 21:35:21,213 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testResolvedSinkFields/resolvedfields/_temporary
2016-05-17 21:35:21,215 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:12.954, using cpu time: 00:03.090
2016-05-17 21:35:21,289 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testResolvedSinkFields/resolvedfields
2016-05-17 21:35:21,348 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:35:21,348 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:21,391 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.015
2016-05-17 21:35:21,408 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-17 21:35:21,409 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:21,410 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:21,410 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:35:21,426 INFO hadoop.Hfs (Hfs.java:makeLocal(445)) - forcing job to stand-alone mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-05-17 21:35:21,426 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tap forcing step to tez local mode: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt
2016-05-17 21:35:21,427 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tap forcing step to tez local mode: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob
2016-05-17 21:35:21,472 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:35:21,473 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:21,518 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-05-17 21:35:21,526 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-05-17 21:35:21,529 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:21,529 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:21,529 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:35:21,601 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting
2016-05-17 21:35:21,603 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] parallel execution of flows is enabled: true
2016-05-17 21:35:21,603 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] executing total flows: 2
2016-05-17 21:35:21,603 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] allocating management threads: 2
2016-05-17 21:35:21,604 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: first
2016-05-17 21:35:21,604 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-17 21:35:21,605 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 21:35:21,608 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:21,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-17 21:35:21,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] source: GlobHfs[/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt]
2016-05-17 21:35:21,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"]
2016-05-17 21:35:21,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] parallel execution of steps is enabled: true
2016-05-17 21:35:21,631 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executing total steps: 1
2016-05-17 21:35:21,631 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] allocating management threads: 1
2016-05-17 21:35:21,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...platform/testGlobHfs/glob
2016-05-17 21:35:21,644 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tez session mode enabled: false
2016-05-17 21:35:21,648 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:35:21,650 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:35:21,650 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520921649_0001
2016-05-17 21:35:21,650 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(159)) - Ignoring 'tez.lib.uris' since 'tez.ignore.lib.uris' is set to true
2016-05-17 21:35:21,656 INFO client.TezClient (TezCommonUtils.java:getTezBaseStagingPath(85)) - Stage directory /tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB doesn't exist and is created
2016-05-17 21:35:21,667 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory file:/tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB/.tez/application_1463520921649_0001 doesn't exist and is created
2016-05-17 21:35:21,705 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520921649_0001, dagName=[80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB] first/(1/1) ...platform/testGlobHfs/glob
2016-05-17 21:35:21,706 INFO client.LocalClient (LocalClient.java:createDAGAppMaster(328)) - DAGAppMaster thread has been created
2016-05-17 21:35:21,706 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(251)) - DAGAppMaster is not created wait for 100ms...
2016-05-17 21:35:21,707 INFO client.LocalClient (LocalClient.java:run(275)) - Using staging directory: /tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB/.tez/application_1463520921649_0001
2016-05-17 21:35:21,719 INFO app.DAGAppMaster (DAGAppMaster.java:<init>(309)) - Created DAGAppMaster for application appattempt_1463520921649_0001_000000, versionInfo=[ component=tez-dag, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:35:21,736 INFO app.DAGAppMaster (DAGAppMaster.java:serviceInit(333)) - Comparing client version with AM version, clientVersion=0.6.2, AMVersion=0.6.2
2016-05-17 21:35:21,744 INFO app.DAGAppMaster (DAGAppMaster.java:serviceInit(386)) - Adding session token to jobTokenSecretManager for application
2016-05-17 21:35:21,763 INFO node.AMNodeTracker (AMNodeTracker.java:serviceInit(77)) - blacklistDisablePercent is 33, blacklistingEnabled: false, maxTaskFailuresPerNode: 1
2016-05-17 21:35:21,764 INFO history.HistoryEventHandler (HistoryEventHandler.java:serviceInit(50)) - Initializing HistoryEventHandler
2016-05-17 21:35:21,767 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceInit(66)) - Log file location for SimpleHistoryLoggingService not specified, defaulting to containerLogDir=/tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB/.tez/application_1463520921649_0001/localmode-log-dir
2016-05-17 21:35:21,767 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceInit(88)) - Initializing SimpleHistoryLoggingService, logFileLocation=/tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB/.tez/application_1463520921649_0001/localmode-log-dir/history.txt.appattempt_1463520921649_0001_000000, maxErrors=10
2016-05-17 21:35:21,767 INFO recovery.RecoveryService (RecoveryService.java:serviceInit(109)) - Initializing RecoveryService
2016-05-17 21:35:21,769 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:N/A][Event:AM_LAUNCHED]: appAttemptId=appattempt_1463520921649_0001_000000, appSubmitTime=1463520921711, launchTime=1463520921718
2016-05-17 21:35:21,782 INFO history.HistoryEventHandler (HistoryEventHandler.java:serviceStart(73)) - Starting HistoryEventHandler
2016-05-17 21:35:21,794 INFO client.DAGClientServer (DAGClientServer.java:serviceStart(91)) - Instantiated DAGClientRPCServer at ip-10-123-148-208.ec2.internal/10.123.148.208:36319
2016-05-17 21:35:21,793 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceStart(95)) - Starting SimpleHistoryLoggingService
2016-05-17 21:35:21,797 INFO recovery.RecoveryService (RecoveryService.java:serviceStart(127)) - Starting RecoveryService
2016-05-17 21:35:21,802 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event AM_LAUNCHED to history file
2016-05-17 21:35:21,803 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:N/A][Event:AM_STARTED]: appAttemptId=appattempt_1463520921649_0001_000000, startTime=1463520921803
2016-05-17 21:35:21,804 INFO app.DAGAppMaster (DAGAppMaster.java:serviceStart(1642)) - In Non-Session mode.
2016-05-17 21:35:21,806 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(236)) - DAGAppMaster state: RUNNING
2016-05-17 21:35:21,807 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: N/A
2016-05-17 21:35:21,807 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted tez dag to app master: application_1463520921649_0001, with dag id: dag_1463520921649_0001_1
2016-05-17 21:35:21,817 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event AM_STARTED to history file
2016-05-17 21:35:21,845 INFO app.DAGAppMaster (DAGAppMaster.java:generateDAGVizFile(870)) - Generating DAG graphviz file, dagId=dag_1463520921649_0001_1, filePath=/tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB/.tez/application_1463520921649_0001/localmode-log-dir/dag_1463520921649_0001_1.dot
2016-05-17 21:35:21,848 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend: dag_1463520921649_0001_1
2016-05-17 21:35:21,848 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-05-17 21:35:21,849 INFO app.DAGAppMaster (DAGAppMaster.java:startDAG(2051)) - Running DAG: [80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB] first/(1/1) ...platform/testGlobHfs/glob
2016-05-17 21:35:21 Running Dag: dag_1463520921649_0001_1
2016-05-17 21:35:21,876 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_SUBMITTED to history file
2016-05-17 21:35:21,876 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:DAG_SUBMITTED]: dagID=dag_1463520921649_0001_1, submitTime=1463520921806
2016-05-17 21:35:21,905 INFO impl.VertexImpl (VertexImpl.java:setAdditionalOutputs(4033)) - setting additional outputs for vertex B7BDACD9D427416FB9C564C0BD9F0A6C
2016-05-17 21:35:21,907 INFO impl.DAGImpl (DAGImpl.java:assignDAGScheduler(1381)) - Using DAG Scheduler: org.apache.tez.dag.app.dag.impl.DAGSchedulerNaturalOrderControlled
2016-05-17 21:35:21,909 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:DAG_INITIALIZED]: dagID=dag_1463520921649_0001_1, initTime=1463520921878
2016-05-17 21:35:21,910 INFO impl.DAGImpl (DAGImpl.java:handle(973)) - dag_1463520921649_0001_1 transitioned from NEW to INITED due to event DAG_INIT
2016-05-17 21:35:21,909 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_INITIALIZED to history file
2016-05-17 21:35:21,914 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_STARTED to history file
2016-05-17 21:35:21,914 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:DAG_STARTED]: dagID=dag_1463520921649_0001_1, startTime=1463520921913
2016-05-17 21:35:21,918 INFO impl.DAGImpl (DAGImpl.java:transition(1614)) - Added additional resources : [[]] to classpath
2016-05-17 21:35:21,920 INFO impl.DAGImpl (DAGImpl.java:handle(973)) - dag_1463520921649_0001_1 transitioned from INITED to RUNNING due to event DAG_START
2016-05-17 21:35:21,922 INFO impl.VertexImpl (VertexImpl.java:setupVertex(2068)) - Root Inputs exist for Vertex: B7BDACD9D427416FB9C564C0BD9F0A6C : {C336EA747DD548F0AB5F54C011D43003={InputName=C336EA747DD548F0AB5F54C011D43003}, {Descriptor=ClassName=org.apache.tez.mapreduce.input.MRInput, hasPayload=true}, {ControllerDescriptor=ClassName=org.apache.tez.mapreduce.common.MRInputAMSplitGenerator, hasPayload=false}}
2016-05-17 21:35:21,923 INFO impl.VertexImpl (VertexImpl.java:setupVertex(2078)) - Starting root input initializer for input: C336EA747DD548F0AB5F54C011D43003, with class: [org.apache.tez.mapreduce.common.MRInputAMSplitGenerator]
2016-05-17 21:35:21,923 INFO impl.VertexImpl (VertexImpl.java:assignVertexManager(2191)) - Setting vertexManager to RootInputVertexManager for vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,929 INFO impl.VertexImpl (VertexImpl.java:handleInitEvent(2983)) - Num tasks is -1. Expecting VertexManager/InputInitializers/1-1 split to set #tasks for the vertex vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,929 INFO impl.VertexImpl (VertexImpl.java:handleInitEvent(2987)) - Vertex will initialize from input initializer. vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,931 INFO impl.VertexImpl (VertexImpl.java:setupInputInitializerManager(3933)) - Vertex will initialize via inputInitializers vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]. Starting root input initializers: 1
2016-05-17 21:35:21,935 INFO dag.RootInputInitializerManager (RootInputInitializerManager.java:run(242)) - Starting InputInitializer for Input: C336EA747DD548F0AB5F54C011D43003 on vertex vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,939 INFO common.MRInputAMSplitGenerator (MRInputAMSplitGenerator.java:initialize(92)) - Emitting serialized splits: true
2016-05-17 21:35:21,941 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] transitioned from NEW to INITIALIZING due to event V_INIT
2016-05-17 21:35:21,941 INFO common.MRInputAMSplitGenerator (MRInputAMSplitGenerator.java:initialize(110)) - Input C336EA747DD548F0AB5F54C011D43003 asking for 1 tasks. Headroom: 672 Task Resource: 1024 waves: 1.7
2016-05-17 21:35:21,941 INFO common.MRInputAMSplitGenerator (MRInputAMSplitGenerator.java:initialize(121)) - Grouping input splits
2016-05-17 21:35:21,942 INFO hadoop.MRInputHelpers (MRInputHelpers.java:generateInputSplitsToMem(294)) - Generating mapred api input splits
2016-05-17 21:35:21,960 INFO hadoop.MRInputHelpers (MRInputHelpers.java:generateInputSplitsToMem(300)) - NumSplits: 1, SerializedSize: 400
2016-05-17 21:35:21,962 INFO dag.RootInputInitializerManager (RootInputInitializerManager.java:onSuccess(272)) - Succeeded InputInitializer for Input: C336EA747DD548F0AB5F54C011D43003 on vertex vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,963 INFO impl.VertexImpl (VertexImpl.java:canInitVertex(3195)) - Cannot init vertex: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] numTasks: -1 numUnitializedEdges: 0 numInitializedInputs: 0 initWaitsForRootInitializers: true
2016-05-17 21:35:21,964 INFO impl.VertexImpl (VertexImpl.java:setParallelism(1374)) - Got updated RootInputsSpecs: {C336EA747DD548F0AB5F54C011D43003=forAllWorkUnits=true, update=[1]}
2016-05-17 21:35:21,977 INFO impl.VertexImpl (VertexImpl.java:setParallelism(1393)) - Vertex vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] parallelism set to 1
2016-05-17 21:35:21,977 INFO impl.VertexImpl (VertexImpl.java:canInitVertex(3195)) - Cannot init vertex: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] numTasks: 1 numUnitializedEdges: 0 numInitializedInputs: 0 initWaitsForRootInitializers: true
2016-05-17 21:35:21,985 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:VERTEX_DATA_MOVEMENT_EVENTS_GENERATED]: vertexId=vertex_1463520921649_0001_1_00, eventCount=1
2016-05-17 21:35:21,986 INFO impl.VertexImpl (VertexImpl.java:initializeCommitters(1915)) - Invoking committer inits for vertex, vertexId=vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,987 INFO impl.VertexImpl (VertexImpl.java:initializeCommitters(1927)) - Instantiating committer for output=DE3DE12DB9EF400CB941E9BF16905127, vertexId=vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C], committerClass=org.apache.tez.mapreduce.committer.MROutputCommitter
2016-05-17 21:35:21,989 INFO impl.VertexImpl (VertexImpl.java:run(1945)) - Invoking committer init for output=DE3DE12DB9EF400CB941E9BF16905127, vertexId=vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:21,996 INFO committer.MROutputCommitter (MROutputCommitter.java:getOutputCommitter(145)) - OutputCommitter for outputName=DE3DE12DB9EF400CB941E9BF16905127, vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, outputCommitterClass=org.apache.hadoop.mapred.FileOutputCommitter
2016-05-17 21:35:22,004 INFO impl.VertexImpl (VertexImpl.java:run(1949)) - Invoking committer setup for output=DE3DE12DB9EF400CB941E9BF16905127, vertexId=vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:22,057 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event VERTEX_INITIALIZED to history file
2016-05-17 21:35:22,057 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:VERTEX_INITIALIZED]: vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, vertexId=vertex_1463520921649_0001_1_00, initRequestedTime=1463520921922, initedTime=1463520922053, numTasks=1, processorName=cascading.flow.tez.FlowProcessor, additionalInputsCount=1
2016-05-17 21:35:22,057 INFO impl.VertexImpl (VertexImpl.java:startIfPossible(3061)) - Triggering start event for vertex: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] with distanceFromRoot: 0
2016-05-17 21:35:22,057 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] transitioned from INITIALIZING to INITED due to event V_ROOT_INPUT_INITIALIZED
2016-05-17 21:35:22,058 INFO impl.ImmediateStartVertexManager (ImmediateStartVertexManager.java:scheduleTasks(99)) - Starting 1 in B7BDACD9D427416FB9C564C0BD9F0A6C
2016-05-17 21:35:22,058 INFO impl.VertexImpl (VertexImpl.java:scheduleTasks(1250)) - Routing pending task events for vertex: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:22,060 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event VERTEX_STARTED to history file
2016-05-17 21:35:22,060 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:VERTEX_STARTED]: vertexId=vertex_1463520921649_0001_1_00, startRequestedTime=1463520922058, startedTime=1463520922058
2016-05-17 21:35:22,060 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] transitioned from INITED to RUNNING due to event V_START
2016-05-17 21:35:22,077 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_STARTED to history file
2016-05-17 21:35:22,077 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:TASK_STARTED]: vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, taskId=task_1463520921649_0001_1_00_000000, scheduledTime=1463520922076, launchTime=1463520922076
2016-05-17 21:35:22,077 INFO impl.TaskImpl (TaskImpl.java:handle(862)) - task_1463520921649_0001_1_00_000000 Task Transitioned from NEW to SCHEDULED due to event T_SCHEDULE
2016-05-17 21:35:22,079 INFO impl.DAGSchedulerNaturalOrderControlled (DAGSchedulerNaturalOrderControlled.java:scheduleTask(111)) - Scheduled vertex: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:22,081 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(1014)) - remoteTaskSpec:DAGName : [80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB] first/(1/1) ...platform/testGlobHfs/glob, VertexName: B7BDACD9D427416FB9C564C0BD9F0A6C, VertexParallelism: 1, TaskAttemptID:attempt_1463520921649_0001_1_00_000000_0, processorName=cascading.flow.tez.FlowProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=C336EA747DD548F0AB5F54C011D43003, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInput }}, ], outputSpecList=[{{ destinationVertexName=DE3DE12DB9EF400CB941E9BF16905127, physicalEdgeCount=0, outputClassName=org.apache.tez.mapreduce.output.MROutput }}, ]
2016-05-17 21:35:22,083 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(692)) - attempt_1463520921649_0001_1_00_000000_0 TaskAttempt Transitioned from NEW to START_WAIT due to event TA_SCHEDULE
2016-05-17 21:35:22,083 INFO rm.TaskSchedulerEventHandler (TaskSchedulerEventHandler.java:handleEvent(149)) - Processing the event EventType: S_TA_LAUNCH_REQUEST
2016-05-17 21:35:22,113 INFO node.AMNodeTracker (AMNodeTracker.java:nodeSeen(91)) - Adding new node: 127.0.0.1:0
2016-05-17 21:35:22,116 INFO container.AMContainerHelpers (AMContainerHelpers.java:createCommonContainerLaunchContext(112)) - Adding #1 tokens and #0 secret keys for NM use for launching container
2016-05-17 21:35:22,117 INFO container.AMContainerHelpers (AMContainerHelpers.java:createCommonContainerLaunchContext(122)) - Putting shuffle token in serviceData
2016-05-17 21:35:22,120 INFO container.AMContainerImpl (AMContainerImpl.java:transition(521)) - Sending Launch Request for Container with id: container_1463520921649_0001_00_000001
2016-05-17 21:35:22,121 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1463520921649_0001_00_000001 transitioned from ALLOCATED to LAUNCHING via event C_LAUNCH_REQUEST
2016-05-17 21:35:22,126 INFO task.TezChild (TezChild.java:newTezChild(432)) - PID, containerIdentifier: null, container_1463520921649_0001_00_000001
2016-05-17 21:35:22,130 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1463520921649_0001_00_000001 transitioned from LAUNCHING to IDLE via event C_LAUNCHED
2016-05-17 21:35:22,130 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event CONTAINER_LAUNCHED to history file
2016-05-17 21:35:22,131 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:CONTAINER_LAUNCHED]: containerId=container_1463520921649_0001_00_000001, launchTime=1463520922130
2016-05-17 21:35:22,134 INFO task.ContainerReporter (ContainerReporter.java:call(55)) - Attempting to fetch new task for container container_1463520921649_0001_00_000001
2016-05-17 21:35:22,136 INFO container.AMContainerImpl (AMContainerImpl.java:transition(827)) - Assigned taskAttempt + [attempt_1463520921649_0001_1_00_000000_0] to container: [container_1463520921649_0001_00_000001]
2016-05-17 21:35:22,136 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1463520921649_0001_00_000001 transitioned from IDLE to RUNNING via event C_PULL_TA
2016-05-17 21:35:22,138 INFO app.TaskAttemptListenerImpTezDag (TaskAttemptListenerImpTezDag.java:getTask(240)) - Container with id: container_1463520921649_0001_00_000001 given task: attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,138 INFO task.ContainerReporter (ContainerReporter.java:call(65)) - Got TaskUpdate for containerId= container_1463520921649_0001_00_000001: 0 ms after starting to poll. TaskInfo: shouldDie: false, currentTaskAttemptId: attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,138 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(1146)) - TaskAttempt: [attempt_1463520921649_0001_1_00_000000_0] started. Is using containerId: [container_1463520921649_0001_00_000001] on NM: [127.0.0.1:0]
2016-05-17 21:35:22 Starting to run new task attempt: attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,140 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:TASK_ATTEMPT_STARTED]: vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, taskAttemptId=attempt_1463520921649_0001_1_00_000000_0, startTime=1463520922137, containerId=container_1463520921649_0001_00_000001, nodeId=127.0.0.1:0, inProgressLogs=127.0.0.1:0/node/containerlogs/container_1463520921649_0001_00_000001/teamcity, completedLogs=
2016-05-17 21:35:22,140 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_ATTEMPT_STARTED to history file
2016-05-17 21:35:22,139 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend: attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,141 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(692)) - attempt_1463520921649_0001_1_00_000000_0 TaskAttempt Transitioned from START_WAIT to RUNNING due to event TA_STARTED_REMOTELY
2016-05-17 21:35:22,141 INFO impl.TaskImpl (TaskImpl.java:handle(862)) - task_1463520921649_0001_1_00_000000 Task Transitioned from SCHEDULED to RUNNING due to event T_ATTEMPT_LAUNCHED
2016-05-17 21:35:22,142 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-05-17 21:35:22,142 INFO task.TezChild (TezChild.java:handleNewTaskCredentials(273)) - Refreshing UGI since Credentials have changed
2016-05-17 21:35:22,143 INFO task.TezChild (TezChild.java:handleNewTaskCredentials(276)) - Credentials : #Tokens=1, #SecretKeys=0
2016-05-17 21:35:22,143 INFO task.TezChild (TezChild.java:handleNewTaskLocalResources(302)) - Localizing additional local resources for Task : {}
2016-05-17 21:35:22,146 INFO task.TezChild (TezChild.java:handleNewTaskLocalResources(312)) - Done localizing additional resources
2016-05-17 21:35:22,154 INFO metrics.TaskCounterUpdater (TaskCounterUpdater.java:initResourceCalculatorPlugin(148)) - Using ResourceCalculatorProcessTree : [ ]
2016-05-17 21:35:22,154 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:<init>(149)) - Initializing LogicalIOProcessorRuntimeTask with TaskSpec: DAGName : [80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB] first/(1/1) ...platform/testGlobHfs/glob, VertexName: B7BDACD9D427416FB9C564C0BD9F0A6C, VertexParallelism: 1, TaskAttemptID:attempt_1463520921649_0001_1_00_000000_0, processorName=cascading.flow.tez.FlowProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=C336EA747DD548F0AB5F54C011D43003, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInput }}, ], outputSpecList=[{{ destinationVertexName=DE3DE12DB9EF400CB941E9BF16905127, physicalEdgeCount=0, outputClassName=org.apache.tez.mapreduce.output.MROutput }}, ]
2016-05-17 21:35:22,156 INFO resources.MemoryDistributor (MemoryDistributor.java:<init>(85)) - InitialMemoryDistributor (isEnabled=true) invoked with: numInputs=1, numOutputs=1, JVM.maxFree=704643072
2016-05-17 21:35:22,161 INFO task.TezTaskRunner (TezTaskRunner.java:run(172)) - Initializing task, taskAttemptId=attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,161 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(191)) - Initializing LogicalProcessorIORuntimeTask
2016-05-17 21:35:22,161 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(195)) - Creating processor, processorClassName=cascading.flow.tez.FlowProcessor
2016-05-17 21:35:22,163 INFO impl.TaskImpl (TaskImpl.java:getTaskAttemptTezEvents(481)) - TaskAttempt:attempt_1463520921649_0001_1_00_000000_0 sent events: (0-1)
2016-05-17 21:35:22,166 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(389)) - Initializing Input using InputSpec: { sourceVertexName=C336EA747DD548F0AB5F54C011D43003, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInput }
2016-05-17 21:35:22,167 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initializeLogicalIOProcessor(488)) - Initializing processor, processorClassName=cascading.flow.tez.FlowProcessor
2016-05-17 21:35:22,168 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(438)) - Initializing Output using OutputSpec: { destinationVertexName=DE3DE12DB9EF400CB941E9BF16905127, physicalEdgeCount=0, outputClassName=org.apache.tez.mapreduce.output.MROutput }
2016-05-17 21:35:22,168 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:createInput(537)) - Creating Input
2016-05-17 21:35:22,169 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(397)) - Initializing Input with src edge: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,172 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:createOutput(565)) - Creating Output
2016-05-17 21:35:22,173 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(446)) - Initializing Output with dest edge: DE3DE12DB9EF400CB941E9BF16905127
2016-05-17 21:35:22,173 INFO output.MROutput (MROutput.java:initialize(347)) - Initializing Simple Output
2016-05-17 21:35:22,175 INFO resources.MemoryDistributor$RequestorInfo (MemoryDistributor.java:<init>(233)) - Received request: 0, type: OUTPUT, componentVertexName: DE3DE12DB9EF400CB941E9BF16905127
2016-05-17 21:35:22,176 INFO resources.MemoryDistributor$RequestorInfo (MemoryDistributor.java:<init>(233)) - Received request: 0, type: INPUT, componentVertexName: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,193 INFO tez.FlowProcessor (FlowProcessor.java:initialize(88)) - cascading version: 3.1.0
2016-05-17 21:35:22,197 INFO input.MRInput (MRInput.java:initialize(440)) - Using New mapreduce API: false, split information via event: true
2016-05-17 21:35:22,198 INFO input.MRInput (MRInput.java:initializeInternal(493)) - Initialzed MRInput: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,198 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(403)) - Initialized Input with src edge: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,210 INFO tez.FlowProcessor (FlowProcessor.java:initialize(94)) - flow node id: B7BDACD9D427416FB9C564C0BD9F0A6C, ordinal: 0
2016-05-17 21:35:22,211 INFO tez.FlowProcessor (LogUtil.java:logMemory(59)) - flow node id: B7BDACD9D427416FB9C564C0BD9F0A6C, mem on start (mb), free: 176, total: 360, max: 672
2016-05-17 21:35:22,211 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initializeLogicalIOProcessor(491)) - Initialized processor, processorClassName=cascading.flow.tez.FlowProcessor
2016-05-17 21:35:22,211 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(220)) - Waiting for 2 initializers to finish
2016-05-17 21:35:22,212 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(220)) - Waiting for 1 initializers to finish
2016-05-17 21:35:22,246 INFO output.MROutput (MROutput.java:initialize(418)) - Initialized Simple Output, using_new_api: false
2016-05-17 21:35:22,246 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(452)) - Initialized Output with dest edge: DE3DE12DB9EF400CB941E9BF16905127
2016-05-17 21:35:22,246 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(233)) - All initializers finished
2016-05-17 21:35:22,247 INFO resources.MemoryDistributor (MemoryDistributor.java:makeInitialAllocations(124)) - Using Allocator class: org.apache.tez.runtime.library.resources.WeightedScalingMemoryDistributor
2016-05-17 21:35:22,253 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:getRequestTypeForClass(197)) - Falling back to RequestType.OTHER for class: org.apache.tez.mapreduce.output.MROutput
2016-05-17 21:35:22,253 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:initialProcessMemoryRequestContext(171)) - ScaleFactor: 1, for type: OTHER
2016-05-17 21:35:22,253 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:getRequestTypeForClass(197)) - Falling back to RequestType.OTHER for class: org.apache.tez.mapreduce.input.MRInput
2016-05-17 21:35:22,254 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:initialProcessMemoryRequestContext(171)) - ScaleFactor: 1, for type: OTHER
2016-05-17 21:35:22,254 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:computeReservedFraction(262)) - InitialReservationFraction=0.3, AdditionalReservationFractionForIOs=0.03, finalReserveFractionUsed=0.32999999999999996
2016-05-17 21:35:22,254 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:assignMemory(126)) - Scaling Requests. NumRequests: 2, numScaledRequests: 2, TotalRequested: 0, TotalRequestedScaled: 0.0, TotalJVMHeap: 704643072, TotalAvailable: 472110858, TotalRequested/TotalJVMHeap:0.00
2016-05-17 21:35:22,254 INFO resources.MemoryDistributor (MemoryDistributor.java:makeInitialAllocations(138)) - Informing: OUTPUT, DE3DE12DB9EF400CB941E9BF16905127, org.apache.tez.mapreduce.output.MROutput: requested=0, allocated=0
2016-05-17 21:35:22,255 INFO resources.MemoryDistributor (MemoryDistributor.java:makeInitialAllocations(138)) - Informing: INPUT, C336EA747DD548F0AB5F54C011D43003, org.apache.tez.mapreduce.input.MRInput: requested=0, allocated=0
2016-05-17 21:35:22,255 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(255)) - Starting Inputs/Outputs
2016-05-17 21:35:22,256 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(268)) - Input: C336EA747DD548F0AB5F54C011D43003 being auto started by the framework. Subsequent instances will not be auto-started
2016-05-17 21:35:22,256 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(419)) - Starting Input with src edge: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,256 INFO input.MRInput (MRInput.java:start(450)) - MRInput setup to received events1
2016-05-17 21:35:22,256 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(421)) - Started Input with src edge: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,256 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(289)) - Num IOs determined for AutoStart: 1
2016-05-17 21:35:22,257 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(291)) - Waiting for 1 IOs to start
2016-05-17 21:35:22,258 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(304)) - AutoStartComplete
2016-05-17 21:35:22,259 INFO task.TezTaskRunner (TezTaskRunner.java:run(175)) - Running task, taskAttemptId=attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,260 INFO input.MRInput (MRInput.java:initFromEventInternal(619)) - Initializing RecordReader from event
2016-05-17 21:35:22,269 INFO input.MRInput (MRInput.java:initFromEventInternal(630)) - Split Details -> SplitClass: org.apache.hadoop.mapred.split.TezGroupedSplit, OldSplit: org.apache.hadoop.mapred.split.TezGroupedSplit@4eaa326e
2016-05-17 21:35:22,271 INFO lib.MRReaderMapred (MRReaderMapred.java:setIncrementalConfigParams(163)) - Processing split: org.apache.hadoop.mapred.split.TezGroupedSplit@4eaa326e
2016-05-17 21:35:22,271 INFO input.MRInput (MRInput.java:initFromEventInternal(634)) - Initialized RecordReader from event
2016-05-17 21:35:22,271 INFO input.MRInput (MRInput.java:processSplitEvent(586)) - Notifying on RecordReader Initialized
2016-05-17 21:35:22,288 INFO graph.Hadoop2TezStreamGraph (Hadoop2TezStreamGraph.java:buildGraph(151)) - using streamed source: GlobHfs[/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt]
2016-05-17 21:35:22,300 INFO tez.FlowProcessor (FlowProcessor.java:run(121)) - sourcing from: GlobHfs[/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt] streamed: true, id: C336EA747DD548F0AB5F54C011D43003
2016-05-17 21:35:22,300 INFO tez.FlowProcessor (FlowProcessor.java:run(124)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"], id: DE3DE12DB9EF400CB941E9BF16905127
2016-05-17 21:35:22,300 INFO element.TezSinkStage (TezSinkStage.java:prepare(57)) - calling MROutput#start() on: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"]
2016-05-17 21:35:22,302 INFO element.TezSourceStage (TezSourceStage.java:prepare(63)) - calling MRInput#start() on: GlobHfs[/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt]
2016-05-17 21:35:22,302 INFO input.MRInput (MRInput.java:start(450)) - MRInput setup to received events1
2016-05-17 21:35:22,304 INFO tez.FlowProcessor (FlowProcessor.java:waitForInputsReady(202)) - flow node id: B7BDACD9D427416FB9C564C0BD9F0A6C, all 1 inputs ready in: 00:00:00.001
2016-05-17 21:35:22,307 INFO output.MROutput (MROutput.java:flush(534)) - Flushing Simple Output
2016-05-17 21:35:22,327 INFO output.MROutput (MROutput.java:flush(544)) - Flushed Simple Output
2016-05-17 21:35:22,329 INFO app.TaskAttemptListenerImpTezDag (TaskAttemptListenerImpTezDag.java:canCommit(353)) - Commit go/no-go request from attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,329 INFO impl.TaskImpl (TaskImpl.java:canCommit(750)) - attempt_1463520921649_0001_1_00_000000_0 given a go for committing the task output.
2016-05-17 21:35:22,333 INFO task.TezTaskRunner (TezTaskRunner.java:run(177)) - Closing task, taskAttemptId=attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,334 INFO tez.FlowProcessor (LogUtil.java:logMemory(59)) - flow node id: B7BDACD9D427416FB9C564C0BD9F0A6C, mem on close (mb), free: 168, total: 360, max: 672
2016-05-17 21:35:22 Completed running task attempt: attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,337 INFO task.TezTaskRunner (TezTaskRunner.java:run(181)) - Task completed, taskAttemptId=attempt_1463520921649_0001_1_00_000000_0, fatalErrorOccurred=false
2016-05-17 21:35:22,340 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:cleanup(712)) - Final Counters : Counters: 26 [[File System Counters FILE_BYTES_READ=38, FILE_BYTES_WRITTEN=516, FILE_READ_OPS=0, FILE_LARGE_READ_OPS=0, FILE_WRITE_OPS=0, HDFS_BYTES_READ=0, HDFS_BYTES_WRITTEN=40, HDFS_READ_OPS=3, HDFS_LARGE_READ_OPS=0, HDFS_WRITE_OPS=2][org.apache.tez.common.counters.TaskCounter GC_TIME_MILLIS=0, CPU_MILLISECONDS=0, PHYSICAL_MEMORY_BYTES=0, VIRTUAL_MEMORY_BYTES=0, COMMITTED_HEAP_BYTES=377487360, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10][cascading.flow.SliceCounters Process_Begin_Time=1463520922304, Process_Duration=29, Process_End_Time=1463520922333, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=1][cascading.flow.StepCounters Tuples_Read=10, Tuples_Written=10]]
2016-05-17 21:35:22,340 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_ATTEMPT_FINISHED to history file
2016-05-17 21:35:22,340 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend:
2016-05-17 21:35:22,341 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-05-17 21:35:22,342 INFO task.ContainerReporter (ContainerReporter.java:call(55)) - Attempting to fetch new task for container container_1463520921649_0001_00_000001
2016-05-17 21:35:22,345 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:TASK_ATTEMPT_FINISHED]: vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, taskAttemptId=attempt_1463520921649_0001_1_00_000000_0, startTime=1463520922137, finishTime=1463520922338, timeTaken=201, status=SUCCEEDED, errorEnum=, diagnostics=, counters=Counters: 27, org.apache.tez.common.counters.DAGCounter, RACK_LOCAL_TASKS=1, File System Counters, FILE_BYTES_READ=38, FILE_BYTES_WRITTEN=516, FILE_READ_OPS=0, FILE_LARGE_READ_OPS=0, FILE_WRITE_OPS=0, HDFS_BYTES_READ=0, HDFS_BYTES_WRITTEN=40, HDFS_READ_OPS=3, HDFS_LARGE_READ_OPS=0, HDFS_WRITE_OPS=2, org.apache.tez.common.counters.TaskCounter, GC_TIME_MILLIS=0, CPU_MILLISECONDS=0, PHYSICAL_MEMORY_BYTES=0, VIRTUAL_MEMORY_BYTES=0, COMMITTED_HEAP_BYTES=377487360, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1463520922304, Process_Duration=29, Process_End_Time=1463520922333, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=1, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10
2016-05-17 21:35:22,346 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(692)) - attempt_1463520921649_0001_1_00_000000_0 TaskAttempt Transitioned from RUNNING to SUCCEEDED due to event TA_DONE
2016-05-17 21:35:22,346 INFO rm.TaskSchedulerEventHandler (TaskSchedulerEventHandler.java:handleEvent(149)) - Processing the event EventType: S_TA_ENDED
2016-05-17 21:35:22,347 INFO impl.TaskImpl (TaskImpl.java:transition(1052)) - Task succeeded with attempt attempt_1463520921649_0001_1_00_000000_0
2016-05-17 21:35:22,349 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_FINISHED to history file
2016-05-17 21:35:22,350 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:TASK_FINISHED]: vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, taskId=task_1463520921649_0001_1_00_000000, startTime=1463520922137, finishTime=1463520922348, timeTaken=211, status=SUCCEEDED, successfulAttemptID=attempt_1463520921649_0001_1_00_000000_0, diagnostics=, counters=Counters: 27, org.apache.tez.common.counters.DAGCounter, RACK_LOCAL_TASKS=1, File System Counters, FILE_BYTES_READ=38, FILE_BYTES_WRITTEN=516, FILE_READ_OPS=0, FILE_LARGE_READ_OPS=0, FILE_WRITE_OPS=0, HDFS_BYTES_READ=0, HDFS_BYTES_WRITTEN=40, HDFS_READ_OPS=3, HDFS_LARGE_READ_OPS=0, HDFS_WRITE_OPS=2, org.apache.tez.common.counters.TaskCounter, GC_TIME_MILLIS=0, CPU_MILLISECONDS=0, PHYSICAL_MEMORY_BYTES=0, VIRTUAL_MEMORY_BYTES=0, COMMITTED_HEAP_BYTES=377487360, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1463520922304, Process_Duration=29, Process_End_Time=1463520922333, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=1, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10
2016-05-17 21:35:22,356 INFO impl.TaskImpl (TaskImpl.java:handle(862)) - task_1463520921649_0001_1_00_000000 Task Transitioned from RUNNING to SUCCEEDED due to event T_ATTEMPT_SUCCEEDED
2016-05-17 21:35:22,357 INFO impl.VertexImpl (VertexImpl.java:transition(3536)) - Num completed Tasks for vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] : 1
2016-05-17 21:35:22,357 INFO impl.VertexImpl (VertexImpl.java:checkVertexForCompletion(1674)) - Vertex succeeded: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:22,363 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event VERTEX_FINISHED to history file
2016-05-17 21:35:22,368 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:VERTEX_FINISHED]: vertexName=B7BDACD9D427416FB9C564C0BD9F0A6C, vertexId=vertex_1463520921649_0001_1_00, initRequestedTime=1463520921922, initedTime=1463520922053, startRequestedTime=1463520922058, startedTime=1463520922058, finishTime=1463520922358, timeTaken=300, status=SUCCEEDED, diagnostics=, counters=Counters: 27, org.apache.tez.common.counters.DAGCounter, RACK_LOCAL_TASKS=1, File System Counters, FILE_BYTES_READ=38, FILE_BYTES_WRITTEN=516, FILE_READ_OPS=0, FILE_LARGE_READ_OPS=0, FILE_WRITE_OPS=0, HDFS_BYTES_READ=0, HDFS_BYTES_WRITTEN=40, HDFS_READ_OPS=3, HDFS_LARGE_READ_OPS=0, HDFS_WRITE_OPS=2, org.apache.tez.common.counters.TaskCounter, GC_TIME_MILLIS=0, CPU_MILLISECONDS=0, PHYSICAL_MEMORY_BYTES=0, VIRTUAL_MEMORY_BYTES=0, COMMITTED_HEAP_BYTES=377487360, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1463520922304, Process_Duration=29, Process_End_Time=1463520922333, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=1, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10, vertexStats=firstTaskStartTime=1463520922137, firstTasksToStart=[ task_1463520921649_0001_1_00_000000 ], lastTaskFinishTime=1463520922338, lastTasksToFinish=[ task_1463520921649_0001_1_00_000000 ], minTaskDuration=201, maxTaskDuration=201, avgTaskDuration=201.0, numSuccessfulTasks=1, shortestDurationTasks=[ task_1463520921649_0001_1_00_000000 ], longestDurationTasks=[ task_1463520921649_0001_1_00_000000 ], vertexTaskStats={numFailedTasks=0, numSucceededTasks=1, numKilledTaskAttempts=0, numKilledTasks=0, numFailedTaskAttempts=0, numCompletedTasks=1}
2016-05-17 21:35:22,369 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] transitioned from RUNNING to SUCCEEDED due to event V_TASK_COMPLETED
2016-05-17 21:35:22,369 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1463520921649_0001_00_000001 transitioned from RUNNING to IDLE via event C_TA_SUCCEEDED
2016-05-17 21:35:22,370 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event CONTAINER_STOPPED to history file
2016-05-17 21:35:22,371 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:CONTAINER_STOPPED]: containerId=container_1463520921649_0001_00_000001, stoppedTime=1463520922370, exitStatus=0
2016-05-17 21:35:22,372 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1463520921649_0001_00_000001 transitioned from IDLE to STOP_REQUESTED via event C_STOP_REQUEST
2016-05-17 21:35:22,372 INFO impl.DAGImpl (DAGImpl.java:transition(1747)) - Vertex vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C] completed., numCompletedVertices=1, numSuccessfulVertices=1, numFailedVertices=0, numKilledVertices=0, numVertices=1
2016-05-17 21:35:22,372 INFO impl.DAGImpl (DAGImpl.java:commitOrAbortOutputs(831)) - Calling DAG commit/abort for dag: dag_1463520921649_0001_1
2016-05-17 21:35:22,376 INFO app.TaskAttemptListenerImpTezDag (TaskAttemptListenerImpTezDag.java:getTask(213)) - Container with id: container_1463520921649_0001_00_000001 is valid, but no longer registered, and will be killed
2016-05-17 21:35:22,376 INFO task.ContainerReporter (ContainerReporter.java:call(65)) - Got TaskUpdate for containerId= container_1463520921649_0001_00_000001: 34 ms after starting to poll. TaskInfo: shouldDie: true
2016-05-17 21:35:22,377 INFO task.TezChild (TezChild.java:run(207)) - ContainerTask returned shouldDie=true for container container_1463520921649_0001_00_000001, Exiting
2016-05-17 21:35:22,377 INFO task.TezChild (TezChild.java:shutdown(343)) - Shutdown invoked for container container_1463520921649_0001_00_000001
2016-05-17 21:35:22,377 INFO task.TezChild (TezChild.java:shutdown(345)) - Shutting down container container_1463520921649_0001_00_000001
2016-05-17 21:35:22,379 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:DAG_COMMIT_STARTED]: dagID=dag_1463520921649_0001_1
2016-05-17 21:35:22,379 INFO impl.DAGImpl (DAGImpl.java:commitOrAbortOutputs(892)) - Committing output: DE3DE12DB9EF400CB941E9BF16905127 for vertex: vertex_1463520921649_0001_1_00 [B7BDACD9D427416FB9C564C0BD9F0A6C]
2016-05-17 21:35:22,380 INFO launcher.LocalContainerLauncher (LocalContainerLauncher.java:onSuccess(270)) - ContainerExecutionResult for: container_1463520921649_0001_00_000001 = ContainerExecutionResult{exitStatus=SUCCESS, throwable=null, errorMessage='Asked to die by the AM'}
2016-05-17 21:35:22,382 INFO launcher.LocalContainerLauncher (LocalContainerLauncher.java:onSuccess(274)) - Container: container_1463520921649_0001_00_000001 completed successfully
2016-05-17 21:35:22,405 INFO recovery.RecoveryService (RecoveryService.java:handle(306)) - DAG completed, dagId=dag_1463520921649_0001_1, queueSize=0
2016-05-17 21:35:22,405 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_FINISHED to history file
2016-05-17 21:35:22,409 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1463520921649_0001_1][Event:DAG_FINISHED]: dagId=dag_1463520921649_0001_1, startTime=1463520921913, finishTime=1463520922400, timeTaken=487, status=SUCCEEDED, diagnostics=, counters=Counters: 29, org.apache.tez.common.counters.DAGCounter, NUM_SUCCEEDED_TASKS=1, TOTAL_LAUNCHED_TASKS=1, RACK_LOCAL_TASKS=1, File System Counters, FILE_BYTES_READ=38, FILE_BYTES_WRITTEN=516, FILE_READ_OPS=0, FILE_LARGE_READ_OPS=0, FILE_WRITE_OPS=0, HDFS_BYTES_READ=0, HDFS_BYTES_WRITTEN=40, HDFS_READ_OPS=3, HDFS_LARGE_READ_OPS=0, HDFS_WRITE_OPS=2, org.apache.tez.common.counters.TaskCounter, GC_TIME_MILLIS=0, CPU_MILLISECONDS=0, PHYSICAL_MEMORY_BYTES=0, VIRTUAL_MEMORY_BYTES=0, COMMITTED_HEAP_BYTES=377487360, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1463520922304, Process_Duration=29, Process_End_Time=1463520922333, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=1, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10
2016-05-17 21:35:22,411 INFO impl.DAGImpl (DAGImpl.java:finished(1180)) - DAG: dag_1463520921649_0001_1 finished with state: SUCCEEDED
2016-05-17 21:35:22,411 INFO impl.DAGImpl (DAGImpl.java:handle(973)) - dag_1463520921649_0001_1 transitioned from RUNNING to SUCCEEDED due to event DAG_VERTEX_COMPLETED
2016-05-17 21:35:22,411 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1463520921649_0001_00_000001 transitioned from STOP_REQUESTED to COMPLETED via event C_COMPLETED
2016-05-17 21:35:22,411 INFO launcher.LocalContainerLauncher (LocalContainerLauncher.java:stop(242)) - Ignoring stop request for containerId: container_1463520921649_0001_00_000001
2016-05-17 21:35:22 Completed Dag: dag_1463520921649_0001_1
2016-05-17 21:35:22,414 INFO app.DAGAppMaster (DAGAppMaster.java:handle(571)) - Not a session, AM will unregister as DAG has completed
2016-05-17 21:35:22,414 INFO rm.TaskSchedulerEventHandler (TaskSchedulerEventHandler.java:setShouldUnregisterFlag(580)) - TaskScheduler notified that it should unregister from RM
2016-05-17 21:35:22,415 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend: dag_1463520921649_0001_1_post
2016-05-17 21:35:22,415 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-05-17 21:35:22,415 INFO app.DAGAppMaster (DAGAppMaster.java:setStateOnDAGCompletion(1068)) - On DAG completion. Old state: RUNNING new state: SUCCEEDED
2016-05-17 21:35:22,415 INFO app.DAGAppMaster (DAGAppMaster.java:handle(575)) - Shutting down on completion of dag:dag_1463520921649_0001_1
2016-05-17 21:35:22,415 INFO app.DAGAppMaster (DAGAppMaster.java:shutdown(692)) - DAGAppMasterShutdownHandler invoked
2016-05-17 21:35:22,415 INFO app.DAGAppMaster (DAGAppMaster.java:shutdown(701)) - Handling DAGAppMaster shutdown
2016-05-17 21:35:22,418 INFO app.DAGAppMaster (DAGAppMaster.java:run(721)) - Sleeping for 5 seconds before shutting down
2016-05-17 21:35:22,424 INFO history.HistoryEventHandler (HistoryEventHandler.java:serviceStop(79)) - Stopping HistoryEventHandler
2016-05-17 21:35:22,425 INFO recovery.RecoveryService (RecoveryService.java:serviceStop(189)) - Stopping RecoveryService
2016-05-17 21:35:22,425 INFO recovery.RecoveryService (RecoveryService.java:serviceStop(192)) - Handle the remaining events in queue, queue size=0
2016-05-17 21:35:22,425 INFO recovery.RecoveryService (RecoveryService.java:run(166)) - EventQueue take interrupted. Returning
2016-05-17 21:35:22,426 INFO recovery.RecoveryService (RecoveryService.java:serviceStop(214)) - Closing Summary Stream
2016-05-17 21:35:22,426 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceStop(118)) - Stopping SimpleHistoryLoggingService, eventQueueBacklog=0
2016-05-17 21:35:22,426 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:run(105)) - EventQueue take interrupted. Returning
2016-05-17 21:35:22,434 INFO app.DAGAppMaster (DAGAppMaster.java:run(1773)) - Completed deletion of tez scratch data dir, path=file:/tmp/hadoop-teamcity/.staging/80C8F5C1DB984A74A5504E429815E4C5/AF19E1255EAA4C90A0D57B20FE280EFB/.tez/application_1463520921649_0001
2016-05-17 21:35:22,436 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob/_temporary
2016-05-17 21:35:22,437 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] completed in: 00:00.804
2016-05-17 21:35:22,437 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: first
2016-05-17 21:35:22,437 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: second
2016-05-17 21:35:22,437 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] at least one sink is marked for delete
2016-05-17 21:35:22,438 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 21:35:22,441 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/5F62D3A737A04A55A2DECB02F823C59F/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:22,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-17 21:35:22,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"]
2016-05-17 21:35:22,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob2"]
2016-05-17 21:35:22,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] parallel execution of steps is enabled: true
2016-05-17 21:35:22,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executing total steps: 1
2016-05-17 21:35:22,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] allocating management threads: 1
2016-05-17 21:35:22,474 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...latform/testGlobHfs/glob2
2016-05-17 21:35:22,488 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tez session mode enabled: false
2016-05-17 21:35:22,492 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:35:22,506 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:35:22,507 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0003
2016-05-17 21:35:22,507 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:35:22,520 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/5F62D3A737A04A55A2DECB02F823C59F/B5A8240320BA4B29A8764AFEB00D8C13/.tez/application_1463520886428_0003 doesn't exist and is created
2016-05-17 21:35:22,583 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0003, dagName=[5F62D3A737A04A55A2DECB02F823C59F/B5A8240320BA4B29A8764AFEB00D8C13] second/(1/1) ...latform/testGlobHfs/glob2
2016-05-17 21:35:22,587 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0003/
2016-05-17 21:35:22,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted tez dag to app master: application_1463520886428_0003, with dag id: dag_1463520886428_0003_1
2016-05-17 21:35:26,264 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0002_01_000002 is : 143
2016-05-17 21:35:27,418 INFO app.DAGAppMaster (DAGAppMaster.java:run(731)) - Calling stop for all the services
2016-05-17 21:35:27,422 INFO app.DAGAppMaster (DAGAppMaster.java:run(742)) - Exiting DAGAppMaster..GoodBye!
2016-05-17 21:35:35,621 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob2/_temporary
2016-05-17 21:35:35,622 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] completed in: 00:13.107, using cpu time: 00:03.040
2016-05-17 21:35:35,623 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: second
2016-05-17 21:35:35,654 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testGlobHfs/glob2
2016-05-17 21:35:35,661 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testGlobHfs/glob
2016-05-17 21:35:35,695 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:35:35,696 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:35,749 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-05-17 21:35:35,773 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.048
2016-05-17 21:35:35,773 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:35:35,774 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:35:35,774 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:35:35,866 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/AE46A7E2ADAA4DA199AFB0C1E9C2FB9B/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:35,887 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:35:35,888 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: ["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-05-17 21:35:35,888 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResource/preparetap"]
2016-05-17 21:35:35,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:35:35,891 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:35:35,891 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:35:35,892 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...repareResource/preparetap
2016-05-17 21:35:35,906 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tez session mode enabled: false
2016-05-17 21:35:35,910 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:35:35,924 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:35:35,924 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0004
2016-05-17 21:35:35,925 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:35:35,938 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/AE46A7E2ADAA4DA199AFB0C1E9C2FB9B/DD7A1902CE744CAD82A3C5A395EB7EF4/.tez/application_1463520886428_0004 doesn't exist and is created
2016-05-17 21:35:36,019 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0004, dagName=[AE46A7E2ADAA4DA199AFB0C1E9C2FB9B/DD7A1902CE744CAD82A3C5A395EB7EF4] test/(1/1) ...repareResource/preparetap
2016-05-17 21:35:36,023 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0004/
2016-05-17 21:35:36,037 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted tez dag to app master: application_1463520886428_0004, with dag id: dag_1463520886428_0004_1
2016-05-17 21:35:40,603 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0003_01_000002 is : 143
2016-05-17 21:35:48,319 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResource/preparetap/_temporary
2016-05-17 21:35:48,320 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:12.390, using cpu time: 00:03.740
2016-05-17 21:35:48,357 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testPrepareResource/preparetap
2016-05-17 21:35:48,420 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:35:48,420 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:48,462 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-05-17 21:35:48,468 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-17 21:35:48,468 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:48,469 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:35:48,469 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:35:48,498 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/71AC1D7814D240BB8A4F667B0DFF937E/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:35:48,518 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:35:48,519 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['a', 'b']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower-offset.txt"]
2016-05-17 21:35:48,519 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: PartitionTap["Hfs["TextDelimited[['a']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testTemporarySinkPathIsDeleted/partition-tap-sink"]"]["cascading.tap.partition.DelimitedPartition@557a7fab"]["[]"]
2016-05-17 21:35:48,520 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:35:48,520 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:35:48,520 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:35:48,521 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...eleted/partition-tap-sink
2016-05-17 21:35:48,536 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tez session mode enabled: false
2016-05-17 21:35:48,541 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:35:48,554 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:35:48,556 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0005
2016-05-17 21:35:48,556 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:35:48,566 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/71AC1D7814D240BB8A4F667B0DFF937E/AB9376195EED45449043371DC0B8003B/.tez/application_1463520886428_0005 doesn't exist and is created
2016-05-17 21:35:48,630 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0005, dagName=[71AC1D7814D240BB8A4F667B0DFF937E/AB9376195EED45449043371DC0B8003B] test/(1/1) ...eleted/partition-tap-sink
2016-05-17 21:35:48,633 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0005/
2016-05-17 21:35:48,647 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted tez dag to app master: application_1463520886428_0005, with dag id: dag_1463520886428_0005_1
2016-05-17 21:35:53,305 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0004_01_000002 is : 143
2016-05-17 21:36:02,371 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testTemporarySinkPathIsDeleted/partition-tap-sink/_temporary
2016-05-17 21:36:02,374 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:13.811, using cpu time: 00:03.220
2016-05-17 21:36:02,387 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testTemporarySinkPathIsDeleted/partition-tap-sink
2016-05-17 21:36:02,427 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:02,427 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:02,455 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: UNSUPPORTED, in: 00:00.001
2016-05-17 21:36:02,489 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-05-17 21:36:02,490 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: NoHashJoinHadoop2TezRuleRegistry, does not support assembly
2016-05-17 21:36:02,491 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:36:02,491 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: HashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:02,550 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/790C39E7BD0144E795CB1591B7D7F934/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:02,575 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-17 21:36:02,575 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["DupeConfigScheme[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/upper.txt"]
2016-05-17 21:36:02,576 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-05-17 21:36:02,576 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testDupeConfigFromScheme/dupeconfig"]
2016-05-17 21:36:02,577 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: true
2016-05-17 21:36:02,577 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-17 21:36:02,577 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-17 21:36:02,578 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...nfigFromScheme/dupeconfig
2016-05-17 21:36:02,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tez session mode enabled: false
2016-05-17 21:36:02,604 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:36:02,624 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:36:02,625 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0006
2016-05-17 21:36:02,626 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:36:02,636 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/790C39E7BD0144E795CB1591B7D7F934/D21FA38EB14D4FDA9C46D2C1CA6A08CA/.tez/application_1463520886428_0006 doesn't exist and is created
2016-05-17 21:36:02,696 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0006, dagName=[790C39E7BD0144E795CB1591B7D7F934/D21FA38EB14D4FDA9C46D2C1CA6A08CA] lower*upper/(1/1) ...nfigFromScheme/dupeconfig
2016-05-17 21:36:02,699 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0006/
2016-05-17 21:36:02,713 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted tez dag to app master: application_1463520886428_0006, with dag id: dag_1463520886428_0006_1
2016-05-17 21:36:07,388 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0005_01_000002 is : 143
2016-05-17 21:36:14,620 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testDupeConfigFromScheme/dupeconfig/_temporary
2016-05-17 21:36:14,621 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:12.002, using cpu time: 00:03.240
2016-05-17 21:36:14,697 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testDupeConfigFromScheme/dupeconfig
2016-05-17 21:36:14,726 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:14,726 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:14,762 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.011
2016-05-17 21:36:14,772 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-05-17 21:36:14,772 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:36:14,773 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:36:14,773 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:14,835 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:14,836 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:14,875 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.012
2016-05-17 21:36:14,882 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.020
2016-05-17 21:36:14,883 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:36:14,883 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 21:36:14,883 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:14,952 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting
2016-05-17 21:36:14,954 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] parallel execution of flows is enabled: true
2016-05-17 21:36:14,954 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] executing total flows: 2
2016-05-17 21:36:14,954 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] allocating management threads: 2
2016-05-17 21:36:14,955 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: first
2016-05-17 21:36:14,955 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-17 21:36:14,956 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 21:36:14,959 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/ED6B9F676771443D90A7696A8F7E0F20/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:14,980 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-17 21:36:14,980 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] source: MultiSourceTap[2:[GlobHfs[/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r]}.txt], GlobHfs[/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{owe?}.txt]]]
2016-05-17 21:36:14,980 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource"]
2016-05-17 21:36:14,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] parallel execution of steps is enabled: true
2016-05-17 21:36:14,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executing total steps: 1
2016-05-17 21:36:14,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] allocating management threads: 1
2016-05-17 21:36:14,982 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...ceGlobHfs/globmultisource
2016-05-17 21:36:14,995 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tez session mode enabled: false
2016-05-17 21:36:14,998 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:36:15,011 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:36:15,012 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0007
2016-05-17 21:36:15,013 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:36:15,024 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/ED6B9F676771443D90A7696A8F7E0F20/CA8FE46E78284058A55C8B9C28E4DCCD/.tez/application_1463520886428_0007 doesn't exist and is created
2016-05-17 21:36:15,083 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0007, dagName=[ED6B9F676771443D90A7696A8F7E0F20/CA8FE46E78284058A55C8B9C28E4DCCD] first/(1/1) ...ceGlobHfs/globmultisource
2016-05-17 21:36:15,085 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0007/
2016-05-17 21:36:15,100 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted tez dag to app master: application_1463520886428_0007, with dag id: dag_1463520886428_0007_1
2016-05-17 21:36:19,621 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0006_01_000002 is : 143
2016-05-17 21:36:26,598 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource/_temporary
2016-05-17 21:36:26,599 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] completed in: 00:11.576, using cpu time: 00:03.010
2016-05-17 21:36:26,600 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: first
2016-05-17 21:36:26,600 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: second
2016-05-17 21:36:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] at least one sink is marked for delete
2016-05-17 21:36:26,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 21:36:26,602 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/F5BC264D85E9455FBE51C9099FC9DBDA/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:26,622 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-17 21:36:26,622 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource"]
2016-05-17 21:36:26,622 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultiource2"]
2016-05-17 21:36:26,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] parallel execution of steps is enabled: true
2016-05-17 21:36:26,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executing total steps: 1
2016-05-17 21:36:26,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] allocating management threads: 1
2016-05-17 21:36:26,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...ceGlobHfs/globmultiource2
2016-05-17 21:36:26,638 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tez session mode enabled: false
2016-05-17 21:36:26,641 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:36:26,655 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:36:26,656 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0008
2016-05-17 21:36:26,656 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:36:26,665 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/F5BC264D85E9455FBE51C9099FC9DBDA/C10AE0BC9EF441868D27966D239B0989/.tez/application_1463520886428_0008 doesn't exist and is created
2016-05-17 21:36:26,721 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0008, dagName=[F5BC264D85E9455FBE51C9099FC9DBDA/C10AE0BC9EF441868D27966D239B0989] second/(1/1) ...ceGlobHfs/globmultiource2
2016-05-17 21:36:26,724 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0008/
2016-05-17 21:36:26,738 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted tez dag to app master: application_1463520886428_0008, with dag id: dag_1463520886428_0008_1
2016-05-17 21:36:31,580 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0007_01_000002 is : 143
2016-05-17 21:36:39,871 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultiource2/_temporary
2016-05-17 21:36:39,872 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] completed in: 00:13.208, using cpu time: 00:02.960
2016-05-17 21:36:39,872 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: second
2016-05-17 21:36:39,900 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource
2016-05-17 21:36:39,905 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultiource2
2016-05-17 21:36:40,033 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:40,033 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:40,078 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-17 21:36:40,093 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-17 21:36:40,094 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:40,094 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:40,094 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:40,172 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/D8D8F46F52C14AB4B23A1C1DCB341FA2/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:40,192 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:36:40,192 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-05-17 21:36:40,193 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResourceForWriteFails/preparewritetapfail"]
2016-05-17 21:36:40,193 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:36:40,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:36:40,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:36:40,196 ERROR flow.Flow (BaseFlow.java:logError(1540)) - [test] unable to prepare tap for write: hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResourceForWriteFails/preparewritetapfail
java.io.IOException: failed intentionally
at cascading.tap.hadoop.HadoopTapPlatformTest$7.prepareResourceForWrite(HadoopTapPlatformTest.java:777)
at cascading.tap.hadoop.HadoopTapPlatformTest$7.prepareResourceForWrite(HadoopTapPlatformTest.java:773)
at cascading.flow.planner.BaseFlowStep.prepareResource(BaseFlowStep.java:614)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:596)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:582)
at cascading.flow.planner.FlowStepJob.prepareResources(FlowStepJob.java:221)
at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:180)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:146)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:48)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-17 21:36:40,199 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-17 21:36:40,199 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) ...Fails/preparewritetapfail
2016-05-17 21:36:40,199 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] getDagStatus returned null
2016-05-17 21:36:40,200 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-17 21:36:40,203 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.008
2016-05-17 21:36:40,203 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testPrepareResourceForWriteFails/preparewritetapfail
2016-05-17 21:36:40,229 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:40,229 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:40,281 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-17 21:36:40,303 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.046
2016-05-17 21:36:40,303 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:40,304 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:40,304 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:40,385 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/7442463B038E4688999611FF5B07180C/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:40,409 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:36:40,409 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: ["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-05-17 21:36:40,410 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResourceForReadFails/preparereadtapfail"]
2016-05-17 21:36:40,410 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:36:40,410 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:36:40,411 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:36:40,412 ERROR flow.Flow (BaseFlow.java:logError(1540)) - [test] unable to prepare tap for read: hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt
java.io.IOException: failed intentionally
at cascading.tap.hadoop.HadoopTapPlatformTest$6.prepareResourceForRead(HadoopTapPlatformTest.java:729)
at cascading.tap.hadoop.HadoopTapPlatformTest$6.prepareResourceForRead(HadoopTapPlatformTest.java:725)
at cascading.flow.planner.BaseFlowStep.prepareResource(BaseFlowStep.java:616)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:596)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:579)
at cascading.flow.planner.FlowStepJob.prepareResources(FlowStepJob.java:221)
at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:180)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:146)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:48)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-17 21:36:40,414 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-17 21:36:40,415 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) ...dFails/preparereadtapfail
2016-05-17 21:36:40,415 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] getDagStatus returned null
2016-05-17 21:36:40,415 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-17 21:36:40,417 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.006
2016-05-17 21:36:40,417 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testPrepareResourceForReadFails/preparereadtapfail
2016-05-17 21:36:40,446 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:40,446 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:40,508 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-05-17 21:36:40,522 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-17 21:36:40,522 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:40,522 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:40,522 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:40,605 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/B62DD5E950C3454FA9A712015C69A756/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:40,624 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:36:40,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-05-17 21:36:40,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResourceFails/committapfail"]
2016-05-17 21:36:40,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:36:40,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:36:40,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:36:40,626 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...sourceFails/committapfail
2016-05-17 21:36:40,640 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tez session mode enabled: false
2016-05-17 21:36:40,642 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:36:40,656 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:36:40,657 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0009
2016-05-17 21:36:40,657 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:36:40,667 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/B62DD5E950C3454FA9A712015C69A756/E8566AAC5D4240DBA263946CDE5383D2/.tez/application_1463520886428_0009 doesn't exist and is created
2016-05-17 21:36:40,719 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0009, dagName=[B62DD5E950C3454FA9A712015C69A756/E8566AAC5D4240DBA263946CDE5383D2] test/(1/1) ...sourceFails/committapfail
2016-05-17 21:36:40,722 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0009/
2016-05-17 21:36:40,736 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted tez dag to app master: application_1463520886428_0009, with dag id: dag_1463520886428_0009_1
2016-05-17 21:36:44,874 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0008_01_000002 is : 143
2016-05-17 21:36:45,854 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1463520886428_0008_01_000002
2016-05-17 21:36:52,990 ERROR flow.Flow (BaseFlow.java:logError(1540)) - [test] unable to commit sink: hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResourceFails/committapfail
java.io.IOException: failed intentionally
at cascading.tap.hadoop.HadoopTapPlatformTest$2.commitResource(HadoopTapPlatformTest.java:403)
at cascading.tap.hadoop.HadoopTapPlatformTest$2.commitResource(HadoopTapPlatformTest.java:399)
at cascading.flow.planner.BaseFlowStep.commitResource(BaseFlowStep.java:660)
at cascading.flow.planner.BaseFlowStep.commitSinks(BaseFlowStep.java:648)
at cascading.flow.planner.FlowStepJob.blockOnJob(FlowStepJob.java:301)
at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:184)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:146)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:48)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-17 21:36:52,995 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-17 21:36:52,995 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) ...sourceFails/committapfail
2016-05-17 21:36:52,996 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-17 21:36:53,038 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResourceFails/committapfail/_temporary
2016-05-17 21:36:53,039 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:12.373, using cpu time: 00:03.550
2016-05-17 21:36:53,040 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testCommitResourceFails/committapfail
2016-05-17 21:36:53,069 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 21:36:53,069 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(151)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:53,109 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-05-17 21:36:53,121 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-17 21:36:53,121 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:53,121 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 21:36:53,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 21:36:53,198 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(556)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.1.0/226af02e24d5195c60e4ebe911d0c7c9780f59f0/cascading-hadoop2-tez-3.1.0.jar, to: hdfs://localhost:34374/user/teamcity/.staging/882737313FEE4C57814260F10B834A89/cascading-hadoop2-tez-3.1.0.jar
2016-05-17 21:36:53,218 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 21:36:53,218 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-05-17 21:36:53,218 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResource/committap"]
2016-05-17 21:36:53,219 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: true
2016-05-17 21:36:53,219 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-17 21:36:53,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-17 21:36:53,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tCommitResource/committap
2016-05-17 21:36:53,234 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tez session mode enabled: false
2016-05-17 21:36:53,237 INFO client.TezClient (TezClient.java:<init>(153)) - Tez Client Version: [ component=tez-api, version=0.6.2, revision=c04283bf91fd96823eec37056d5c8b1a92728265, SCM-URL=scm:git:https://git-wip-us.apache.org/repos/asf/tez.git, buildTime=20150804-1436 ]
2016-05-17 21:36:53,250 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-05-17 21:36:53,250 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1463520886428_0010
2016-05-17 21:36:53,251 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:34374/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-05-17 21:36:53,260 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:34374/user/teamcity/.staging/882737313FEE4C57814260F10B834A89/EE499B95666B4155B98B09EA4784961F/.tez/application_1463520886428_0010 doesn't exist and is created
2016-05-17 21:36:53,314 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1463520886428_0010, dagName=[882737313FEE4C57814260F10B834A89/EE499B95666B4155B98B09EA4784961F] test/(1/1) ...tCommitResource/committap
2016-05-17 21:36:53,317 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-123-148-208:49087/proxy/application_1463520886428_0010/
2016-05-17 21:36:53,330 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted tez dag to app master: application_1463520886428_0010, with dag id: dag_1463520886428_0010_1
2016-05-17 21:36:58,028 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463520886428_0009_01_000002 is : 143
2016-05-17 21:37:06,564 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResource/committap/_temporary
2016-05-17 21:37:06,565 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:13.304, using cpu time: 00:03.690
2016-05-17 21:37:06,593 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testCommitResource/committap
2016-05-17 21:37:06,661 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,661 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-17 21:37:06,664 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A/part-00000
2016-05-17 21:37:06,677 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,684 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A
2016-05-17 21:37:06,685 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A/_temporary
2016-05-17 21:37:06,701 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,702 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-17 21:37:06,704 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B/part-00000
2016-05-17 21:37:06,720 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,726 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B
2016-05-17 21:37:06,727 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B/_temporary
2016-05-17 21:37:06,773 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,774 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-17 21:37:06,777 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A/part-00000
2016-05-17 21:37:06,794 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,802 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A
2016-05-17 21:37:06,803 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A/_temporary
2016-05-17 21:37:06,822 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,822 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-17 21:37:06,826 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B/part-00000
2016-05-17 21:37:06,839 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,845 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B
2016-05-17 21:37:06,846 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B/_temporary
2016-05-17 21:37:06,862 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,862 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-17 21:37:06,866 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden/part-00000
2016-05-17 21:37:06,878 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden/_temporary/_attempt_002147483647_0000_m_000000_0
2016-05-17 21:37:06,884 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden
2016-05-17 21:37:06,885 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:34374/opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden/_temporary
2016-05-17 21:37:06,898 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden
2016-05-17 21:37:06,903 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B
2016-05-17 21:37:06,907 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A
2016-05-17 21:37:06,911 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles
2016-05-17 21:37:06,918 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B
2016-05-17 21:37:06,922 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A
2016-05-17 21:37:06,926 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/2f4c45215847827d/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles