2016-01-14 16:13:06,312 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 16:13:06,330 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.tap.hadoop.HadoopTapPlatformTest, with platform: hadoop2-tez
2016-01-14 16:13:06,359 INFO tez.Hadoop2TezPlatform (Hadoop2TezPlatform.java:setUp(164)) - using cluster
2016-01-14 16:13:07,044 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
Formatting using clusterid: testClusterID
2016-01-14 16:13:07,975 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 16:13:08,517 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 16:13:10,879 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-01-14 16:13:11,109 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(121)) - Set TEZ-LIB-URI to: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:13:11,115 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(152)) - mkdir: hdfs://localhost:46576/apps_staging_dir
2016-01-14 16:13:11,470 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-01-14 16:13:11,559 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-01-14 16:13:11,606 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-01-14 16:13:11,691 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-01-14 16:13:11,696 INFO test.MiniTezCluster (MiniTezCluster.java:serviceStart(186)) - Starting MiniTezCluster
2016-01-14 16:13:17,330 INFO test.MiniTezCluster (MiniTezCluster.java:serviceStart(205)) - Setting yarn-site.xml via YARN-APP-CP at: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/target/cascading.platform.tez.Hadoop2TezPlatform,/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/resources/test:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/main:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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.0.4/f8041cf548c12cc6e997a63a67562fcf5b2e237/cascading-core-3.0.4-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-platform/3.0.4/2c7c4ae0a2ac3b7e296414816e065fb601e9be39/cascading-platform-3.0.4-tests.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/4f45ecd85538b8cc8c352ccd4f33c52c1776a545/cascading-hadoop2-tez-3.0.4-tests.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.1/872b4fd3a6d8a4f0bdfb0f6e26c4499e752ce39/jgrapht-core-0.9.1.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/cascading/cascading-core/3.0.4/db7694f29f171efa077bb0192f3c3039f7514807/cascading-core-3.0.4.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/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.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/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-01-14 16:13:17,717 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 16:13:17,820 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:13:17,821 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:17,893 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: BC2B567E379D48BE8B24E877FC5F3383
2016-01-14 16:13:18,057 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-01-14 16:13:18,066 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.067
2016-01-14 16:13:18,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:18,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:18,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:13:18,282 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/32356AC2F0E84A3487F78809F53D95BB/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:18,343 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 16:13:18,346 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:13:18,346 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["CommentScheme[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/comments+lower.txt"]
2016-01-14 16:13:18,346 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNullsFromScheme/testnulls"]
2016-01-14 16:13:18,347 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:13:18,347 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:13:18,347 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:13:18,348 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...NullsFromScheme/testnulls
2016-01-14 16:13:18,370 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tez session mode enabled: false
2016-01-14 16:13:18,392 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-01-14 16:13:18,473 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:13:18,508 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0001
2016-01-14 16:13:18,509 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:13:18,527 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/32356AC2F0E84A3487F78809F53D95BB/F0616E27F48A459BBAA3FA628272A89F/.tez/application_1452787991698_0001 doesn't exist and is created
2016-01-14 16:13:18,696 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0001, dagName=[32356AC2F0E84A3487F78809F53D95BB/F0616E27F48A459BBAA3FA628272A89F] test/(1/1) ...NullsFromScheme/testnulls
2016-01-14 16:13:18,774 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0001/
2016-01-14 16:13:18,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted tez dag to app master: application_1452787991698_0001, with dag id: dag_1452787991698_0001_1
2016-01-14 16:13:33,808 INFO client.TimelineReaderFactory (TimelineReaderFactory.java:tokenDelegationSupported(381)) - Could not find class required for token delegation, will fallback to pseudo auth
2016-01-14 16:13:33,842 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-01-14 16:13:33,844 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:15.497, using cpu time: 00:03.000
2016-01-14 16:13:33,996 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testNullsFromScheme/testnulls
2016-01-14 16:13:34,066 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:13:34,067 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:34,133 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-01-14 16:13:34,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-01-14 16:13:34,159 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:13:34,159 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:13:34,159 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:13:34,207 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testMissingInputFormat/missinginputformat
2016-01-14 16:13:34,458 INFO hadoop.Hfs (Hfs.java:makeLocal(428)) - forcing job to local mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/upper.txt"]
2016-01-14 16:13:34,533 INFO hadoop.Hfs (Hfs.java:makeLocal(428)) - forcing job to local mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-01-14 16:13:34,620 INFO hadoop.Hfs (Hfs.java:makeLocal(428)) - forcing job to local mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-01-14 16:13:34,686 INFO hadoop.Hfs (Hfs.java:makeLocal(428)) - forcing job to local mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/upper.txt"]
2016-01-14 16:13:34,727 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:13:34,727 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:34,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 16:13:34,788 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-01-14 16:13:34,789 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:34,790 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:34,790 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:13:34,827 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/17A25017CE42410CB1D8D6F95CDF5C2B/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:34,860 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:13:34,861 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-01-14 16:13:34,861 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["ResolvedScheme[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testResolvedSinkFields/resolvedfields"]
2016-01-14 16:13:34,862 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:13:34,863 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:13:34,863 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:13:34,864 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...SinkFields/resolvedfields
2016-01-14 16:13:34,878 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tez session mode enabled: false
2016-01-14 16:13:34,882 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-01-14 16:13:34,897 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:13:34,898 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0002
2016-01-14 16:13:34,898 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:13:34,912 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/17A25017CE42410CB1D8D6F95CDF5C2B/AD9A66083C594FF68E8171871CD76F80/.tez/application_1452787991698_0002 doesn't exist and is created
2016-01-14 16:13:34,986 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0002, dagName=[17A25017CE42410CB1D8D6F95CDF5C2B/AD9A66083C594FF68E8171871CD76F80] test/(1/1) ...SinkFields/resolvedfields
2016-01-14 16:13:34,992 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0002/
2016-01-14 16:13:35,008 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted tez dag to app master: application_1452787991698_0002, with dag id: dag_1452787991698_0002_1
2016-01-14 16:13:38,846 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0001_01_000002 is : 143
2016-01-14 16:13:39,833 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452787991698_0001_01_000002
2016-01-14 16:13:49,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:14.541, using cpu time: 00:03.140
2016-01-14 16:13:49,471 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testResolvedSinkFields/resolvedfields
2016-01-14 16:13:49,529 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:13:49,529 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:49,585 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 16:13:49,585 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-01-14 16:13:49,587 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:49,587 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:49,588 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:13:49,608 INFO hadoop.Hfs (Hfs.java:makeLocal(428)) - forcing job to local mode, via source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["file:/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-01-14 16:13:49,608 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tap forcing step to tez local mode: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt
2016-01-14 16:13:49,610 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tap forcing step to tez local mode: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob
2016-01-14 16:13:49,654 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:13:49,655 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:49,696 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.013
2016-01-14 16:13:49,706 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 16:13:49,706 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:49,708 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:13:49,708 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:13:49,772 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting
2016-01-14 16:13:49,775 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] parallel execution of flows is enabled: true
2016-01-14 16:13:49,775 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] executing total flows: 2
2016-01-14 16:13:49,775 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] allocating management threads: 2
2016-01-14 16:13:49,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: first
2016-01-14 16:13:49,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 16:13:49,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 16:13:49,781 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:49,808 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 16:13:49,808 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] source: GlobHfs[/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt]
2016-01-14 16:13:49,809 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"]
2016-01-14 16:13:49,809 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] parallel execution of steps is enabled: true
2016-01-14 16:13:49,809 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executing total steps: 1
2016-01-14 16:13:49,810 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] allocating management threads: 1
2016-01-14 16:13:49,811 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...platform/testGlobHfs/glob
2016-01-14 16:13:49,824 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tez session mode enabled: false
2016-01-14 16:13:49,828 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-01-14 16:13:49,830 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:13:49,830 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452788029829_0001
2016-01-14 16:13:49,830 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(159)) - Ignoring 'tez.lib.uris' since 'tez.ignore.lib.uris' is set to true
2016-01-14 16:13:49,836 INFO client.TezClient (TezCommonUtils.java:getTezBaseStagingPath(85)) - Stage directory /tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259 doesn't exist and is created
2016-01-14 16:13:49,847 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory file:/tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259/.tez/application_1452788029829_0001 doesn't exist and is created
2016-01-14 16:13:49,882 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452788029829_0001, dagName=[C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259] first/(1/1) ...platform/testGlobHfs/glob
2016-01-14 16:13:49,883 INFO client.LocalClient (LocalClient.java:createDAGAppMaster(328)) - DAGAppMaster thread has been created
2016-01-14 16:13:49,883 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(251)) - DAGAppMaster is not created wait for 100ms...
2016-01-14 16:13:49,884 INFO client.LocalClient (LocalClient.java:run(275)) - Using staging directory: /tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259/.tez/application_1452788029829_0001
2016-01-14 16:13:49,896 INFO app.DAGAppMaster (DAGAppMaster.java:<init>(309)) - Created DAGAppMaster for application appattempt_1452788029829_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-01-14 16:13:49,930 INFO app.DAGAppMaster (DAGAppMaster.java:serviceInit(333)) - Comparing client version with AM version, clientVersion=0.6.2, AMVersion=0.6.2
2016-01-14 16:13:49,937 INFO app.DAGAppMaster (DAGAppMaster.java:serviceInit(386)) - Adding session token to jobTokenSecretManager for application
2016-01-14 16:13:49,956 INFO node.AMNodeTracker (AMNodeTracker.java:serviceInit(77)) - blacklistDisablePercent is 33, blacklistingEnabled: false, maxTaskFailuresPerNode: 1
2016-01-14 16:13:49,956 INFO history.HistoryEventHandler (HistoryEventHandler.java:serviceInit(50)) - Initializing HistoryEventHandler
2016-01-14 16:13:49,960 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceInit(66)) - Log file location for SimpleHistoryLoggingService not specified, defaulting to containerLogDir=/tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259/.tez/application_1452788029829_0001/localmode-log-dir
2016-01-14 16:13:49,960 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceInit(88)) - Initializing SimpleHistoryLoggingService, logFileLocation=/tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259/.tez/application_1452788029829_0001/localmode-log-dir/history.txt.appattempt_1452788029829_0001_000000, maxErrors=10
2016-01-14 16:13:49,960 INFO recovery.RecoveryService (RecoveryService.java:serviceInit(109)) - Initializing RecoveryService
2016-01-14 16:13:49,962 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:N/A][Event:AM_LAUNCHED]: appAttemptId=appattempt_1452788029829_0001_000000, appSubmitTime=1452788029888, launchTime=1452788029895
2016-01-14 16:13:49,973 INFO history.HistoryEventHandler (HistoryEventHandler.java:serviceStart(73)) - Starting HistoryEventHandler
2016-01-14 16:13:49,981 INFO client.DAGClientServer (DAGClientServer.java:serviceStart(91)) - Instantiated DAGClientRPCServer at ip-10-187-41-40.ec2.internal/10.187.41.40:60132
2016-01-14 16:13:49,983 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(236)) - DAGAppMaster state: INITED
2016-01-14 16:13:49,984 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(240)) - DAGAppMaster is not startetd wait for 100ms...
2016-01-14 16:13:49,984 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(251)) - DAGAppMaster is not created wait for 100ms...
2016-01-14 16:13:49,983 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceStart(95)) - Starting SimpleHistoryLoggingService
2016-01-14 16:13:49,985 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event AM_LAUNCHED to history file
2016-01-14 16:13:49,988 INFO recovery.RecoveryService (RecoveryService.java:serviceStart(127)) - Starting RecoveryService
2016-01-14 16:13:49,993 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:N/A][Event:AM_STARTED]: appAttemptId=appattempt_1452788029829_0001_000000, startTime=1452788029992
2016-01-14 16:13:49,993 INFO app.DAGAppMaster (DAGAppMaster.java:serviceStart(1642)) - In Non-Session mode.
2016-01-14 16:13:49,998 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event AM_STARTED to history file
2016-01-14 16:13:50,019 INFO app.DAGAppMaster (DAGAppMaster.java:generateDAGVizFile(870)) - Generating DAG graphviz file, dagId=dag_1452788029829_0001_1, filePath=/tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259/.tez/application_1452788029829_0001/localmode-log-dir/dag_1452788029829_0001_1.dot
2016-01-14 16:13:50,022 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend: dag_1452788029829_0001_1
2016-01-14 16:13:50,023 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-01-14 16:13:50,023 INFO app.DAGAppMaster (DAGAppMaster.java:startDAG(2051)) - Running DAG: [C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259] first/(1/1) ...platform/testGlobHfs/glob
2016-01-14 16:13:50 Running Dag: dag_1452788029829_0001_1
2016-01-14 16:13:50,047 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_SUBMITTED to history file
2016-01-14 16:13:50,047 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:DAG_SUBMITTED]: dagID=dag_1452788029829_0001_1, submitTime=1452788029994
2016-01-14 16:13:50,075 INFO impl.VertexImpl (VertexImpl.java:setAdditionalOutputs(4033)) - setting additional outputs for vertex DB890FC5DECD42BA8E420FCCCEEC5083
2016-01-14 16:13:50,077 INFO impl.DAGImpl (DAGImpl.java:assignDAGScheduler(1381)) - Using DAG Scheduler: org.apache.tez.dag.app.dag.impl.DAGSchedulerNaturalOrderControlled
2016-01-14 16:13:50,079 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_INITIALIZED to history file
2016-01-14 16:13:50,079 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:DAG_INITIALIZED]: dagID=dag_1452788029829_0001_1, initTime=1452788030048
2016-01-14 16:13:50,080 INFO impl.DAGImpl (DAGImpl.java:handle(973)) - dag_1452788029829_0001_1 transitioned from NEW to INITED due to event DAG_INIT
2016-01-14 16:13:50,082 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_STARTED to history file
2016-01-14 16:13:50,082 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:DAG_STARTED]: dagID=dag_1452788029829_0001_1, startTime=1452788030081
2016-01-14 16:13:50,084 INFO client.LocalClient (LocalClient.java:startDAGAppMaster(236)) - DAGAppMaster state: RUNNING
2016-01-14 16:13:50,082 INFO impl.DAGImpl (DAGImpl.java:transition(1614)) - Added additional resources : [[]] to classpath
2016-01-14 16:13:50,086 INFO impl.DAGImpl (DAGImpl.java:handle(973)) - dag_1452788029829_0001_1 transitioned from INITED to RUNNING due to event DAG_START
2016-01-14 16:13:50,086 INFO impl.VertexImpl (VertexImpl.java:setupVertex(2068)) - Root Inputs exist for Vertex: DB890FC5DECD42BA8E420FCCCEEC5083 : {C41751FE485642D9AEEBF131C31AD575={InputName=C41751FE485642D9AEEBF131C31AD575}, {Descriptor=ClassName=org.apache.tez.mapreduce.input.MRInput, hasPayload=true}, {ControllerDescriptor=ClassName=org.apache.tez.mapreduce.common.MRInputAMSplitGenerator, hasPayload=false}}
2016-01-14 16:13:50,087 INFO impl.VertexImpl (VertexImpl.java:setupVertex(2078)) - Starting root input initializer for input: C41751FE485642D9AEEBF131C31AD575, with class: [org.apache.tez.mapreduce.common.MRInputAMSplitGenerator]
2016-01-14 16:13:50,087 INFO impl.VertexImpl (VertexImpl.java:assignVertexManager(2191)) - Setting vertexManager to RootInputVertexManager for vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,093 INFO impl.VertexImpl (VertexImpl.java:handleInitEvent(2983)) - Num tasks is -1. Expecting VertexManager/InputInitializers/1-1 split to set #tasks for the vertex vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,094 INFO impl.VertexImpl (VertexImpl.java:handleInitEvent(2987)) - Vertex will initialize from input initializer. vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,095 INFO impl.VertexImpl (VertexImpl.java:setupInputInitializerManager(3933)) - Vertex will initialize via inputInitializers vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]. Starting root input initializers: 1
2016-01-14 16:13:50,099 INFO dag.RootInputInitializerManager (RootInputInitializerManager.java:run(242)) - Starting InputInitializer for Input: C41751FE485642D9AEEBF131C31AD575 on vertex vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,103 INFO common.MRInputAMSplitGenerator (MRInputAMSplitGenerator.java:initialize(92)) - Emitting serialized splits: true
2016-01-14 16:13:50,104 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] transitioned from NEW to INITIALIZING due to event V_INIT
2016-01-14 16:13:50,104 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: N/A
2016-01-14 16:13:50,105 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted tez dag to app master: application_1452788029829_0001, with dag id: dag_1452788029829_0001_1
2016-01-14 16:13:50,105 INFO common.MRInputAMSplitGenerator (MRInputAMSplitGenerator.java:initialize(110)) - Input C41751FE485642D9AEEBF131C31AD575 asking for 1 tasks. Headroom: 672 Task Resource: 1024 waves: 1.7
2016-01-14 16:13:50,105 INFO common.MRInputAMSplitGenerator (MRInputAMSplitGenerator.java:initialize(121)) - Grouping input splits
2016-01-14 16:13:50,106 INFO hadoop.MRInputHelpers (MRInputHelpers.java:generateInputSplitsToMem(294)) - Generating mapred api input splits
2016-01-14 16:13:50,125 INFO hadoop.MRInputHelpers (MRInputHelpers.java:generateInputSplitsToMem(300)) - NumSplits: 1, SerializedSize: 400
2016-01-14 16:13:50,128 INFO dag.RootInputInitializerManager (RootInputInitializerManager.java:onSuccess(272)) - Succeeded InputInitializer for Input: C41751FE485642D9AEEBF131C31AD575 on vertex vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,130 INFO impl.VertexImpl (VertexImpl.java:canInitVertex(3195)) - Cannot init vertex: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] numTasks: -1 numUnitializedEdges: 0 numInitializedInputs: 0 initWaitsForRootInitializers: true
2016-01-14 16:13:50,130 INFO impl.VertexImpl (VertexImpl.java:setParallelism(1374)) - Got updated RootInputsSpecs: {C41751FE485642D9AEEBF131C31AD575=forAllWorkUnits=true, update=[1]}
2016-01-14 16:13:50,142 INFO impl.VertexImpl (VertexImpl.java:setParallelism(1393)) - Vertex vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] parallelism set to 1
2016-01-14 16:13:50,142 INFO impl.VertexImpl (VertexImpl.java:canInitVertex(3195)) - Cannot init vertex: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] numTasks: 1 numUnitializedEdges: 0 numInitializedInputs: 0 initWaitsForRootInitializers: true
2016-01-14 16:13:50,149 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:VERTEX_DATA_MOVEMENT_EVENTS_GENERATED]: vertexId=vertex_1452788029829_0001_1_00, eventCount=1
2016-01-14 16:13:50,151 INFO impl.VertexImpl (VertexImpl.java:initializeCommitters(1915)) - Invoking committer inits for vertex, vertexId=vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,151 INFO impl.VertexImpl (VertexImpl.java:initializeCommitters(1927)) - Instantiating committer for output=702FA6F7AE63434692BED2F68FB30095, vertexId=vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083], committerClass=org.apache.tez.mapreduce.committer.MROutputCommitter
2016-01-14 16:13:50,153 INFO impl.VertexImpl (VertexImpl.java:run(1945)) - Invoking committer init for output=702FA6F7AE63434692BED2F68FB30095, vertexId=vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,158 INFO committer.MROutputCommitter (MROutputCommitter.java:getOutputCommitter(145)) - OutputCommitter for outputName=702FA6F7AE63434692BED2F68FB30095, vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, outputCommitterClass=org.apache.hadoop.mapred.FileOutputCommitter
2016-01-14 16:13:50,164 INFO impl.VertexImpl (VertexImpl.java:run(1949)) - Invoking committer setup for output=702FA6F7AE63434692BED2F68FB30095, vertexId=vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,212 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event VERTEX_INITIALIZED to history file
2016-01-14 16:13:50,212 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:VERTEX_INITIALIZED]: vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, vertexId=vertex_1452788029829_0001_1_00, initRequestedTime=1452788030086, initedTime=1452788030211, numTasks=1, processorName=cascading.flow.tez.FlowProcessor, additionalInputsCount=1
2016-01-14 16:13:50,212 INFO impl.VertexImpl (VertexImpl.java:startIfPossible(3061)) - Triggering start event for vertex: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] with distanceFromRoot: 0
2016-01-14 16:13:50,212 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] transitioned from INITIALIZING to INITED due to event V_ROOT_INPUT_INITIALIZED
2016-01-14 16:13:50,214 INFO impl.ImmediateStartVertexManager (ImmediateStartVertexManager.java:scheduleTasks(99)) - Starting 1 in DB890FC5DECD42BA8E420FCCCEEC5083
2016-01-14 16:13:50,214 INFO impl.VertexImpl (VertexImpl.java:scheduleTasks(1250)) - Routing pending task events for vertex: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,215 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event VERTEX_STARTED to history file
2016-01-14 16:13:50,215 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:VERTEX_STARTED]: vertexId=vertex_1452788029829_0001_1_00, startRequestedTime=1452788030213, startedTime=1452788030213
2016-01-14 16:13:50,216 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] transitioned from INITED to RUNNING due to event V_START
2016-01-14 16:13:50,234 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_STARTED to history file
2016-01-14 16:13:50,234 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:TASK_STARTED]: vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, taskId=task_1452788029829_0001_1_00_000000, scheduledTime=1452788030233, launchTime=1452788030233
2016-01-14 16:13:50,234 INFO impl.TaskImpl (TaskImpl.java:handle(862)) - task_1452788029829_0001_1_00_000000 Task Transitioned from NEW to SCHEDULED due to event T_SCHEDULE
2016-01-14 16:13:50,236 INFO impl.DAGSchedulerNaturalOrderControlled (DAGSchedulerNaturalOrderControlled.java:scheduleTask(111)) - Scheduled vertex: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,238 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(1014)) - remoteTaskSpec:DAGName : [C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259] first/(1/1) ...platform/testGlobHfs/glob, VertexName: DB890FC5DECD42BA8E420FCCCEEC5083, VertexParallelism: 1, TaskAttemptID:attempt_1452788029829_0001_1_00_000000_0, processorName=cascading.flow.tez.FlowProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=C41751FE485642D9AEEBF131C31AD575, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInput }}, ], outputSpecList=[{{ destinationVertexName=702FA6F7AE63434692BED2F68FB30095, physicalEdgeCount=0, outputClassName=org.apache.tez.mapreduce.output.MROutput }}, ]
2016-01-14 16:13:50,240 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(692)) - attempt_1452788029829_0001_1_00_000000_0 TaskAttempt Transitioned from NEW to START_WAIT due to event TA_SCHEDULE
2016-01-14 16:13:50,240 INFO rm.TaskSchedulerEventHandler (TaskSchedulerEventHandler.java:handleEvent(149)) - Processing the event EventType: S_TA_LAUNCH_REQUEST
2016-01-14 16:13:50,268 INFO node.AMNodeTracker (AMNodeTracker.java:nodeSeen(91)) - Adding new node: 127.0.0.1:0
2016-01-14 16:13:50,272 INFO container.AMContainerHelpers (AMContainerHelpers.java:createCommonContainerLaunchContext(112)) - Adding #1 tokens and #0 secret keys for NM use for launching container
2016-01-14 16:13:50,272 INFO container.AMContainerHelpers (AMContainerHelpers.java:createCommonContainerLaunchContext(122)) - Putting shuffle token in serviceData
2016-01-14 16:13:50,276 INFO container.AMContainerImpl (AMContainerImpl.java:transition(521)) - Sending Launch Request for Container with id: container_1452788029829_0001_00_000001
2016-01-14 16:13:50,276 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1452788029829_0001_00_000001 transitioned from ALLOCATED to LAUNCHING via event C_LAUNCH_REQUEST
2016-01-14 16:13:50,281 INFO task.TezChild (TezChild.java:newTezChild(432)) - PID, containerIdentifier: null, container_1452788029829_0001_00_000001
2016-01-14 16:13:50,286 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1452788029829_0001_00_000001 transitioned from LAUNCHING to IDLE via event C_LAUNCHED
2016-01-14 16:13:50,286 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event CONTAINER_LAUNCHED to history file
2016-01-14 16:13:50,286 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:CONTAINER_LAUNCHED]: containerId=container_1452788029829_0001_00_000001, launchTime=1452788030286
2016-01-14 16:13:50,289 INFO task.ContainerReporter (ContainerReporter.java:call(55)) - Attempting to fetch new task for container container_1452788029829_0001_00_000001
2016-01-14 16:13:50,290 INFO container.AMContainerImpl (AMContainerImpl.java:transition(827)) - Assigned taskAttempt + [attempt_1452788029829_0001_1_00_000000_0] to container: [container_1452788029829_0001_00_000001]
2016-01-14 16:13:50,290 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1452788029829_0001_00_000001 transitioned from IDLE to RUNNING via event C_PULL_TA
2016-01-14 16:13:50,291 INFO app.TaskAttemptListenerImpTezDag (TaskAttemptListenerImpTezDag.java:getTask(240)) - Container with id: container_1452788029829_0001_00_000001 given task: attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,291 INFO task.ContainerReporter (ContainerReporter.java:call(65)) - Got TaskUpdate for containerId= container_1452788029829_0001_00_000001: 0 ms after starting to poll. TaskInfo: shouldDie: false, currentTaskAttemptId: attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50 Starting to run new task attempt: attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,293 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend: attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,293 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:transition(1146)) - TaskAttempt: [attempt_1452788029829_0001_1_00_000000_0] started. Is using containerId: [container_1452788029829_0001_00_000001] on NM: [127.0.0.1:0]
2016-01-14 16:13:50,294 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-01-14 16:13:50,295 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_ATTEMPT_STARTED to history file
2016-01-14 16:13:50,295 INFO task.TezChild (TezChild.java:handleNewTaskCredentials(273)) - Refreshing UGI since Credentials have changed
2016-01-14 16:13:50,296 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:TASK_ATTEMPT_STARTED]: vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, taskAttemptId=attempt_1452788029829_0001_1_00_000000_0, startTime=1452788030291, containerId=container_1452788029829_0001_00_000001, nodeId=127.0.0.1:0, inProgressLogs=127.0.0.1:0/node/containerlogs/container_1452788029829_0001_00_000001/teamcity, completedLogs=
2016-01-14 16:13:50,296 INFO task.TezChild (TezChild.java:handleNewTaskCredentials(276)) - Credentials : #Tokens=1, #SecretKeys=0
2016-01-14 16:13:50,297 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(692)) - attempt_1452788029829_0001_1_00_000000_0 TaskAttempt Transitioned from START_WAIT to RUNNING due to event TA_STARTED_REMOTELY
2016-01-14 16:13:50,297 INFO impl.TaskImpl (TaskImpl.java:handle(862)) - task_1452788029829_0001_1_00_000000 Task Transitioned from SCHEDULED to RUNNING due to event T_ATTEMPT_LAUNCHED
2016-01-14 16:13:50,297 INFO task.TezChild (TezChild.java:handleNewTaskLocalResources(302)) - Localizing additional local resources for Task : {}
2016-01-14 16:13:50,299 INFO task.TezChild (TezChild.java:handleNewTaskLocalResources(312)) - Done localizing additional resources
2016-01-14 16:13:50,307 INFO metrics.TaskCounterUpdater (TaskCounterUpdater.java:initResourceCalculatorPlugin(148)) - Using ResourceCalculatorProcessTree : [ ]
2016-01-14 16:13:50,307 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:<init>(149)) - Initializing LogicalIOProcessorRuntimeTask with TaskSpec: DAGName : [C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259] first/(1/1) ...platform/testGlobHfs/glob, VertexName: DB890FC5DECD42BA8E420FCCCEEC5083, VertexParallelism: 1, TaskAttemptID:attempt_1452788029829_0001_1_00_000000_0, processorName=cascading.flow.tez.FlowProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=C41751FE485642D9AEEBF131C31AD575, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInput }}, ], outputSpecList=[{{ destinationVertexName=702FA6F7AE63434692BED2F68FB30095, physicalEdgeCount=0, outputClassName=org.apache.tez.mapreduce.output.MROutput }}, ]
2016-01-14 16:13:50,309 INFO resources.MemoryDistributor (MemoryDistributor.java:<init>(85)) - InitialMemoryDistributor (isEnabled=true) invoked with: numInputs=1, numOutputs=1, JVM.maxFree=704643072
2016-01-14 16:13:50,314 INFO task.TezTaskRunner (TezTaskRunner.java:run(172)) - Initializing task, taskAttemptId=attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,314 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(191)) - Initializing LogicalProcessorIORuntimeTask
2016-01-14 16:13:50,315 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(195)) - Creating processor, processorClassName=cascading.flow.tez.FlowProcessor
2016-01-14 16:13:50,318 INFO impl.TaskImpl (TaskImpl.java:getTaskAttemptTezEvents(481)) - TaskAttempt:attempt_1452788029829_0001_1_00_000000_0 sent events: (0-1)
2016-01-14 16:13:50,320 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(389)) - Initializing Input using InputSpec: { sourceVertexName=C41751FE485642D9AEEBF131C31AD575, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInput }
2016-01-14 16:13:50,320 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initializeLogicalIOProcessor(488)) - Initializing processor, processorClassName=cascading.flow.tez.FlowProcessor
2016-01-14 16:13:50,321 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(438)) - Initializing Output using OutputSpec: { destinationVertexName=702FA6F7AE63434692BED2F68FB30095, physicalEdgeCount=0, outputClassName=org.apache.tez.mapreduce.output.MROutput }
2016-01-14 16:13:50,321 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:createInput(537)) - Creating Input
2016-01-14 16:13:50,322 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(397)) - Initializing Input with src edge: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,322 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:createOutput(565)) - Creating Output
2016-01-14 16:13:50,323 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(446)) - Initializing Output with dest edge: 702FA6F7AE63434692BED2F68FB30095
2016-01-14 16:13:50,323 INFO output.MROutput (MROutput.java:initialize(347)) - Initializing Simple Output
2016-01-14 16:13:50,325 INFO resources.MemoryDistributor$RequestorInfo (MemoryDistributor.java:<init>(233)) - Received request: 0, type: OUTPUT, componentVertexName: 702FA6F7AE63434692BED2F68FB30095
2016-01-14 16:13:50,325 INFO resources.MemoryDistributor$RequestorInfo (MemoryDistributor.java:<init>(233)) - Received request: 0, type: INPUT, componentVertexName: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,332 INFO tez.FlowProcessor (FlowProcessor.java:initialize(88)) - cascading version: 3.0.4
2016-01-14 16:13:50,332 INFO input.MRInput (MRInput.java:initialize(440)) - Using New mapreduce API: false, split information via event: true
2016-01-14 16:13:50,333 INFO input.MRInput (MRInput.java:initializeInternal(493)) - Initialzed MRInput: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,335 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(403)) - Initialized Input with src edge: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,345 INFO tez.FlowProcessor (FlowProcessor.java:initialize(94)) - flow node id: DB890FC5DECD42BA8E420FCCCEEC5083, ordinal: 0
2016-01-14 16:13:50,346 INFO tez.FlowProcessor (LogUtil.java:logMemory(59)) - flow node id: DB890FC5DECD42BA8E420FCCCEEC5083, mem on start (mb), free: 227, total: 337, max: 672
2016-01-14 16:13:50,346 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initializeLogicalIOProcessor(491)) - Initialized processor, processorClassName=cascading.flow.tez.FlowProcessor
2016-01-14 16:13:50,346 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(220)) - Waiting for 2 initializers to finish
2016-01-14 16:13:50,346 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(220)) - Waiting for 1 initializers to finish
2016-01-14 16:13:50,387 INFO output.MROutput (MROutput.java:initialize(418)) - Initialized Simple Output, using_new_api: false
2016-01-14 16:13:50,387 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(452)) - Initialized Output with dest edge: 702FA6F7AE63434692BED2F68FB30095
2016-01-14 16:13:50,387 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(233)) - All initializers finished
2016-01-14 16:13:50,388 INFO resources.MemoryDistributor (MemoryDistributor.java:makeInitialAllocations(124)) - Using Allocator class: org.apache.tez.runtime.library.resources.WeightedScalingMemoryDistributor
2016-01-14 16:13:50,398 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:getRequestTypeForClass(197)) - Falling back to RequestType.OTHER for class: org.apache.tez.mapreduce.input.MRInput
2016-01-14 16:13:50,398 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:initialProcessMemoryRequestContext(171)) - ScaleFactor: 1, for type: OTHER
2016-01-14 16:13:50,399 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:getRequestTypeForClass(197)) - Falling back to RequestType.OTHER for class: org.apache.tez.mapreduce.output.MROutput
2016-01-14 16:13:50,399 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:initialProcessMemoryRequestContext(171)) - ScaleFactor: 1, for type: OTHER
2016-01-14 16:13:50,399 INFO resources.WeightedScalingMemoryDistributor (WeightedScalingMemoryDistributor.java:computeReservedFraction(262)) - InitialReservationFraction=0.3, AdditionalReservationFractionForIOs=0.03, finalReserveFractionUsed=0.32999999999999996
2016-01-14 16:13:50,399 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-01-14 16:13:50,400 INFO resources.MemoryDistributor (MemoryDistributor.java:makeInitialAllocations(138)) - Informing: INPUT, C41751FE485642D9AEEBF131C31AD575, org.apache.tez.mapreduce.input.MRInput: requested=0, allocated=0
2016-01-14 16:13:50,400 INFO resources.MemoryDistributor (MemoryDistributor.java:makeInitialAllocations(138)) - Informing: OUTPUT, 702FA6F7AE63434692BED2F68FB30095, org.apache.tez.mapreduce.output.MROutput: requested=0, allocated=0
2016-01-14 16:13:50,400 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(255)) - Starting Inputs/Outputs
2016-01-14 16:13:50,401 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(268)) - Input: C41751FE485642D9AEEBF131C31AD575 being auto started by the framework. Subsequent instances will not be auto-started
2016-01-14 16:13:50,401 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(419)) - Starting Input with src edge: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,401 INFO input.MRInput (MRInput.java:start(450)) - MRInput setup to received events1
2016-01-14 16:13:50,402 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:call(421)) - Started Input with src edge: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,401 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(289)) - Num IOs determined for AutoStart: 1
2016-01-14 16:13:50,402 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(291)) - Waiting for 1 IOs to start
2016-01-14 16:13:50,402 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:initialize(304)) - AutoStartComplete
2016-01-14 16:13:50,404 INFO task.TezTaskRunner (TezTaskRunner.java:run(175)) - Running task, taskAttemptId=attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,404 INFO input.MRInput (MRInput.java:initFromEventInternal(619)) - Initializing RecordReader from event
2016-01-14 16:13:50,410 INFO input.MRInput (MRInput.java:initFromEventInternal(630)) - Split Details -> SplitClass: org.apache.hadoop.mapred.split.TezGroupedSplit, OldSplit: org.apache.hadoop.mapred.split.TezGroupedSplit@4e5a93e7
2016-01-14 16:13:50,412 INFO lib.MRReaderMapred (MRReaderMapred.java:setIncrementalConfigParams(163)) - Processing split: org.apache.hadoop.mapred.split.TezGroupedSplit@4e5a93e7
2016-01-14 16:13:50,412 INFO input.MRInput (MRInput.java:initFromEventInternal(634)) - Initialized RecordReader from event
2016-01-14 16:13:50,412 INFO input.MRInput (MRInput.java:processSplitEvent(586)) - Notifying on RecordReader Initialized
2016-01-14 16:13:50,435 INFO graph.Hadoop2TezStreamGraph (Hadoop2TezStreamGraph.java:buildGraph(151)) - using streamed source: GlobHfs[/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt]
2016-01-14 16:13:50,447 INFO tez.FlowProcessor (FlowProcessor.java:run(121)) - sourcing from: GlobHfs[/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt] streamed: true, id: C41751FE485642D9AEEBF131C31AD575
2016-01-14 16:13:50,447 INFO tez.FlowProcessor (FlowProcessor.java:run(124)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"], id: 702FA6F7AE63434692BED2F68FB30095
2016-01-14 16:13:50,447 INFO element.TezSinkStage (TezSinkStage.java:prepare(57)) - calling MROutput#start() on: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"]
2016-01-14 16:13:50,449 INFO element.TezSourceStage (TezSourceStage.java:prepare(63)) - calling MRInput#start() on: GlobHfs[/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r],owe?}.txt]
2016-01-14 16:13:50,449 INFO input.MRInput (MRInput.java:start(450)) - MRInput setup to received events1
2016-01-14 16:13:50,452 INFO tez.FlowProcessor (FlowProcessor.java:waitForInputsReady(202)) - flow node id: DB890FC5DECD42BA8E420FCCCEEC5083, all 1 inputs ready in: 00:00:00.000
2016-01-14 16:13:50,457 INFO output.MROutput (MROutput.java:flush(534)) - Flushing Simple Output
2016-01-14 16:13:50,473 INFO output.MROutput (MROutput.java:flush(544)) - Flushed Simple Output
2016-01-14 16:13:50,477 INFO app.TaskAttemptListenerImpTezDag (TaskAttemptListenerImpTezDag.java:canCommit(353)) - Commit go/no-go request from attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,478 INFO impl.TaskImpl (TaskImpl.java:canCommit(750)) - attempt_1452788029829_0001_1_00_000000_0 given a go for committing the task output.
2016-01-14 16:13:50,487 INFO task.TezTaskRunner (TezTaskRunner.java:run(177)) - Closing task, taskAttemptId=attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,487 INFO tez.FlowProcessor (LogUtil.java:logMemory(59)) - flow node id: DB890FC5DECD42BA8E420FCCCEEC5083, mem on close (mb), free: 218, total: 337, max: 672
2016-01-14 16:13:50 Completed running task attempt: attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,492 INFO task.TezTaskRunner (TezTaskRunner.java:run(181)) - Task completed, taskAttemptId=attempt_1452788029829_0001_1_00_000000_0, fatalErrorOccurred=false
2016-01-14 16:13:50,494 INFO runtime.LogicalIOProcessorRuntimeTask (LogicalIOProcessorRuntimeTask.java:cleanup(712)) - Final Counters : Counters: 26 [[File System Counters FILE_BYTES_READ=38, FILE_BYTES_WRITTEN=458, 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=353370112, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10][cascading.flow.SliceCounters Process_Begin_Time=1452788030452, Process_Duration=34, Process_End_Time=1452788030486, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=0][cascading.flow.StepCounters Tuples_Read=10, Tuples_Written=10]]
2016-01-14 16:13:50,494 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_ATTEMPT_FINISHED to history file
2016-01-14 16:13:50,499 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend:
2016-01-14 16:13:50,500 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-01-14 16:13:50,500 INFO task.ContainerReporter (ContainerReporter.java:call(55)) - Attempting to fetch new task for container container_1452788029829_0001_00_000001
2016-01-14 16:13:50,507 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:TASK_ATTEMPT_FINISHED]: vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, taskAttemptId=attempt_1452788029829_0001_1_00_000000_0, startTime=1452788030291, finishTime=1452788030493, timeTaken=202, 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=458, 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=353370112, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1452788030452, Process_Duration=34, Process_End_Time=1452788030486, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=0, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10
2016-01-14 16:13:50,508 INFO impl.TaskAttemptImpl (TaskAttemptImpl.java:handle(692)) - attempt_1452788029829_0001_1_00_000000_0 TaskAttempt Transitioned from RUNNING to SUCCEEDED due to event TA_DONE
2016-01-14 16:13:50,508 INFO rm.TaskSchedulerEventHandler (TaskSchedulerEventHandler.java:handleEvent(149)) - Processing the event EventType: S_TA_ENDED
2016-01-14 16:13:50,510 INFO impl.TaskImpl (TaskImpl.java:transition(1052)) - Task succeeded with attempt attempt_1452788029829_0001_1_00_000000_0
2016-01-14 16:13:50,512 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event TASK_FINISHED to history file
2016-01-14 16:13:50,513 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:TASK_FINISHED]: vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, taskId=task_1452788029829_0001_1_00_000000, startTime=1452788030291, finishTime=1452788030511, timeTaken=220, status=SUCCEEDED, successfulAttemptID=attempt_1452788029829_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=458, 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=353370112, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1452788030452, Process_Duration=34, Process_End_Time=1452788030486, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=0, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10
2016-01-14 16:13:50,521 INFO impl.TaskImpl (TaskImpl.java:handle(862)) - task_1452788029829_0001_1_00_000000 Task Transitioned from RUNNING to SUCCEEDED due to event T_ATTEMPT_SUCCEEDED
2016-01-14 16:13:50,522 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1452788029829_0001_00_000001 transitioned from RUNNING to IDLE via event C_TA_SUCCEEDED
2016-01-14 16:13:50,522 INFO impl.VertexImpl (VertexImpl.java:transition(3536)) - Num completed Tasks for vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] : 1
2016-01-14 16:13:50,522 INFO impl.VertexImpl (VertexImpl.java:checkVertexForCompletion(1674)) - Vertex succeeded: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,528 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event VERTEX_FINISHED to history file
2016-01-14 16:13:50,529 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:VERTEX_FINISHED]: vertexName=DB890FC5DECD42BA8E420FCCCEEC5083, vertexId=vertex_1452788029829_0001_1_00, initRequestedTime=1452788030086, initedTime=1452788030211, startRequestedTime=1452788030213, startedTime=1452788030213, finishTime=1452788030523, timeTaken=310, 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=458, 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=353370112, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1452788030452, Process_Duration=34, Process_End_Time=1452788030486, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=0, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10, vertexStats=firstTaskStartTime=1452788030291, firstTasksToStart=[ task_1452788029829_0001_1_00_000000 ], lastTaskFinishTime=1452788030493, lastTasksToFinish=[ task_1452788029829_0001_1_00_000000 ], minTaskDuration=202, maxTaskDuration=202, avgTaskDuration=202.0, numSuccessfulTasks=1, shortestDurationTasks=[ task_1452788029829_0001_1_00_000000 ], longestDurationTasks=[ task_1452788029829_0001_1_00_000000 ], vertexTaskStats={numFailedTasks=0, numSucceededTasks=1, numKilledTaskAttempts=0, numKilledTasks=0, numFailedTaskAttempts=0, numCompletedTasks=1}
2016-01-14 16:13:50,530 INFO impl.VertexImpl (VertexImpl.java:handle(1564)) - vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] transitioned from RUNNING to SUCCEEDED due to event V_TASK_COMPLETED
2016-01-14 16:13:50,534 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:CONTAINER_STOPPED]: containerId=container_1452788029829_0001_00_000001, stoppedTime=1452788030534, exitStatus=0
2016-01-14 16:13:50,535 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1452788029829_0001_00_000001 transitioned from IDLE to STOP_REQUESTED via event C_STOP_REQUEST
2016-01-14 16:13:50,535 INFO app.TaskAttemptListenerImpTezDag (TaskAttemptListenerImpTezDag.java:getTask(213)) - Container with id: container_1452788029829_0001_00_000001 is valid, but no longer registered, and will be killed
2016-01-14 16:13:50,535 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event CONTAINER_STOPPED to history file
2016-01-14 16:13:50,536 INFO impl.DAGImpl (DAGImpl.java:transition(1747)) - Vertex vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083] completed., numCompletedVertices=1, numSuccessfulVertices=1, numFailedVertices=0, numKilledVertices=0, numVertices=1
2016-01-14 16:13:50,536 INFO task.ContainerReporter (ContainerReporter.java:call(65)) - Got TaskUpdate for containerId= container_1452788029829_0001_00_000001: 35 ms after starting to poll. TaskInfo: shouldDie: true
2016-01-14 16:13:50,537 INFO task.TezChild (TezChild.java:run(207)) - ContainerTask returned shouldDie=true for container container_1452788029829_0001_00_000001, Exiting
2016-01-14 16:13:50,537 INFO task.TezChild (TezChild.java:shutdown(343)) - Shutdown invoked for container container_1452788029829_0001_00_000001
2016-01-14 16:13:50,537 INFO task.TezChild (TezChild.java:shutdown(345)) - Shutting down container container_1452788029829_0001_00_000001
2016-01-14 16:13:50,541 INFO launcher.LocalContainerLauncher (LocalContainerLauncher.java:onSuccess(270)) - ContainerExecutionResult for: container_1452788029829_0001_00_000001 = ContainerExecutionResult{exitStatus=SUCCESS, throwable=null, errorMessage='Asked to die by the AM'}
2016-01-14 16:13:50,541 INFO impl.DAGImpl (DAGImpl.java:commitOrAbortOutputs(831)) - Calling DAG commit/abort for dag: dag_1452788029829_0001_1
2016-01-14 16:13:50,541 INFO launcher.LocalContainerLauncher (LocalContainerLauncher.java:onSuccess(274)) - Container: container_1452788029829_0001_00_000001 completed successfully
2016-01-14 16:13:50,543 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:DAG_COMMIT_STARTED]: dagID=dag_1452788029829_0001_1
2016-01-14 16:13:50,543 INFO impl.DAGImpl (DAGImpl.java:commitOrAbortOutputs(892)) - Committing output: 702FA6F7AE63434692BED2F68FB30095 for vertex: vertex_1452788029829_0001_1_00 [DB890FC5DECD42BA8E420FCCCEEC5083]
2016-01-14 16:13:50,567 INFO recovery.RecoveryService (RecoveryService.java:handle(306)) - DAG completed, dagId=dag_1452788029829_0001_1, queueSize=0
2016-01-14 16:13:50,567 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:handleEvent(151)) - Writing event DAG_FINISHED to history file
2016-01-14 16:13:50,567 INFO history.HistoryEventHandler (HistoryEventHandler.java:handleCriticalEvent(110)) - [HISTORY][DAG:dag_1452788029829_0001_1][Event:DAG_FINISHED]: dagId=dag_1452788029829_0001_1, startTime=1452788030081, finishTime=1452788030562, timeTaken=481, 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=458, 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=353370112, INPUT_RECORDS_PROCESSED=0, OUTPUT_RECORDS=10, cascading.flow.SliceCounters, Process_Begin_Time=1452788030452, Process_Duration=34, Process_End_Time=1452788030486, Read_Duration=1, Tuples_Read=10, Tuples_Written=10, Write_Duration=0, cascading.flow.StepCounters, Tuples_Read=10, Tuples_Written=10
2016-01-14 16:13:50,573 INFO impl.DAGImpl (DAGImpl.java:finished(1180)) - DAG: dag_1452788029829_0001_1 finished with state: SUCCEEDED
2016-01-14 16:13:50,573 INFO impl.DAGImpl (DAGImpl.java:handle(973)) - dag_1452788029829_0001_1 transitioned from RUNNING to SUCCEEDED due to event DAG_VERTEX_COMPLETED
2016-01-14 16:13:50,573 INFO container.AMContainerImpl (AMContainerImpl.java:handle(442)) - AMContainer container_1452788029829_0001_00_000001 transitioned from STOP_REQUESTED to COMPLETED via event C_COMPLETED
2016-01-14 16:13:50 Completed Dag: dag_1452788029829_0001_1
2016-01-14 16:13:50,574 INFO app.DAGAppMaster (DAGAppMaster.java:handle(571)) - Not a session, AM will unregister as DAG has completed
2016-01-14 16:13:50,575 INFO launcher.LocalContainerLauncher (LocalContainerLauncher.java:stop(242)) - Ignoring stop request for containerId: container_1452788029829_0001_00_000001
2016-01-14 16:13:50,577 INFO rm.TaskSchedulerEventHandler (TaskSchedulerEventHandler.java:setShouldUnregisterFlag(580)) - TaskScheduler notified that it should unregister from RM
2016-01-14 16:13:50,579 INFO common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(164)) - Redirecting log file based on addend: dag_1452788029829_0001_1_post
2016-01-14 16:13:50,579 WARN common.TezUtilsInternal (TezUtilsInternal.java:updateLoggers(179)) - Not configured with appender named: CLA. Cannot reconfigure logger output
2016-01-14 16:13:50,580 INFO app.DAGAppMaster (DAGAppMaster.java:setStateOnDAGCompletion(1068)) - On DAG completion. Old state: RUNNING new state: SUCCEEDED
2016-01-14 16:13:50,581 INFO app.DAGAppMaster (DAGAppMaster.java:handle(575)) - Shutting down on completion of dag:dag_1452788029829_0001_1
2016-01-14 16:13:50,581 INFO app.DAGAppMaster (DAGAppMaster.java:shutdown(692)) - DAGAppMasterShutdownHandler invoked
2016-01-14 16:13:50,582 INFO app.DAGAppMaster (DAGAppMaster.java:shutdown(701)) - Handling DAGAppMaster shutdown
2016-01-14 16:13:50,592 INFO app.DAGAppMaster (DAGAppMaster.java:run(721)) - Sleeping for 5 seconds before shutting down
2016-01-14 16:13:50,594 INFO history.HistoryEventHandler (HistoryEventHandler.java:serviceStop(79)) - Stopping HistoryEventHandler
2016-01-14 16:13:50,595 INFO recovery.RecoveryService (RecoveryService.java:serviceStop(189)) - Stopping RecoveryService
2016-01-14 16:13:50,595 INFO recovery.RecoveryService (RecoveryService.java:serviceStop(192)) - Handle the remaining events in queue, queue size=0
2016-01-14 16:13:50,595 INFO recovery.RecoveryService (RecoveryService.java:run(166)) - EventQueue take interrupted. Returning
2016-01-14 16:13:50,596 INFO recovery.RecoveryService (RecoveryService.java:serviceStop(214)) - Closing Summary Stream
2016-01-14 16:13:50,596 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:serviceStop(118)) - Stopping SimpleHistoryLoggingService, eventQueueBacklog=0
2016-01-14 16:13:50,596 INFO impl.SimpleHistoryLoggingService (SimpleHistoryLoggingService.java:run(105)) - EventQueue take interrupted. Returning
2016-01-14 16:13:50,605 INFO app.DAGAppMaster (DAGAppMaster.java:run(1773)) - Completed deletion of tez scratch data dir, path=file:/tmp/hadoop-teamcity/.staging/C372DC2F44374ABF8C5CBD9624632EC8/ADE6AC217CBC47ACACE25B1320B43259/.tez/application_1452788029829_0001
2016-01-14 16:13:50,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] completed in: 00:00.798
2016-01-14 16:13:50,609 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: first
2016-01-14 16:13:50,609 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: second
2016-01-14 16:13:50,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] at least one sink is marked for delete
2016-01-14 16:13:50,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 16:13:50,612 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/B7B6B9A8E4994C80B8388BB55D5419F0/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:13:50,640 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 16:13:50,641 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob"]
2016-01-14 16:13:50,641 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testGlobHfs/glob2"]
2016-01-14 16:13:50,641 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] parallel execution of steps is enabled: true
2016-01-14 16:13:50,642 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executing total steps: 1
2016-01-14 16:13:50,642 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] allocating management threads: 1
2016-01-14 16:13:50,643 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...latform/testGlobHfs/glob2
2016-01-14 16:13:50,658 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tez session mode enabled: false
2016-01-14 16:13:50,661 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-01-14 16:13:50,674 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:13:50,675 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0003
2016-01-14 16:13:50,676 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:13:50,688 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/B7B6B9A8E4994C80B8388BB55D5419F0/BE0AE25634D143948F6ED55A1D1784FA/.tez/application_1452787991698_0003 doesn't exist and is created
2016-01-14 16:13:50,754 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0003, dagName=[B7B6B9A8E4994C80B8388BB55D5419F0/BE0AE25634D143948F6ED55A1D1784FA] second/(1/1) ...latform/testGlobHfs/glob2
2016-01-14 16:13:50,759 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0003/
2016-01-14 16:13:50,774 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted tez dag to app master: application_1452787991698_0003, with dag id: dag_1452787991698_0003_1
2016-01-14 16:13:54,457 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0002_01_000002 is : 143
2016-01-14 16:13:55,426 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452787991698_0002_01_000002
2016-01-14 16:13:55,593 INFO app.DAGAppMaster (DAGAppMaster.java:run(731)) - Calling stop for all the services
2016-01-14 16:13:55,597 INFO app.DAGAppMaster (DAGAppMaster.java:run(742)) - Exiting DAGAppMaster..GoodBye!
2016-01-14 16:14:02,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] completed in: 00:12.092, using cpu time: 00:02.950
2016-01-14 16:14:02,733 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: second
2016-01-14 16:14:02,806 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testGlobHfs/glob
2016-01-14 16:14:02,812 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testGlobHfs/glob2
2016-01-14 16:14:02,841 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:02,841 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:02,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 16:14:02,908 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-01-14 16:14:02,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:02,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:02,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:03,012 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/15056BE38B964B42A3B30F001F5B0939/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:03,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:14:03,039 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: ["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-01-14 16:14:03,039 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResource/preparetap"]
2016-01-14 16:14:03,039 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:14:03,040 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:14:03,040 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:14:03,041 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...repareResource/preparetap
2016-01-14 16:14:03,057 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tez session mode enabled: false
2016-01-14 16:14:03,060 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-01-14 16:14:03,075 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:14:03,077 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0004
2016-01-14 16:14:03,077 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:14:03,089 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/15056BE38B964B42A3B30F001F5B0939/C63173A550C4438E8DB169590058D851/.tez/application_1452787991698_0004 doesn't exist and is created
2016-01-14 16:14:03,156 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0004, dagName=[15056BE38B964B42A3B30F001F5B0939/C63173A550C4438E8DB169590058D851] test/(1/1) ...repareResource/preparetap
2016-01-14 16:14:03,160 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0004/
2016-01-14 16:14:03,175 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted tez dag to app master: application_1452787991698_0004, with dag id: dag_1452787991698_0004_1
2016-01-14 16:14:07,763 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0003_01_000002 is : 143
2016-01-14 16:14:16,043 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:13.004, using cpu time: 00:03.710
2016-01-14 16:14:16,117 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testPrepareResource/preparetap
2016-01-14 16:14:16,149 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:16,150 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:16,176 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: UNSUPPORTED, in: 00:00.001
2016-01-14 16:14:16,209 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-01-14 16:14:16,210 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: NoHashJoinHadoop2TezRuleRegistry, does not support assembly
2016-01-14 16:14:16,210 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:14:16,210 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: HashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:16,270 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/517206FBA26B43878718C3C106690841/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:16,294 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 16:14:16,295 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["DupeConfigScheme[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/upper.txt"]
2016-01-14 16:14:16,297 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/lower.txt"]
2016-01-14 16:14:16,297 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testDupeConfigFromScheme/dupeconfig"]
2016-01-14 16:14:16,298 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: true
2016-01-14 16:14:16,298 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 16:14:16,298 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 16:14:16,302 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...nfigFromScheme/dupeconfig
2016-01-14 16:14:16,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tez session mode enabled: false
2016-01-14 16:14:16,327 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-01-14 16:14:16,343 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:14:16,344 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0005
2016-01-14 16:14:16,344 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:14:16,357 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/517206FBA26B43878718C3C106690841/C393404FECF249B4881C36FE8E6EA6BF/.tez/application_1452787991698_0005 doesn't exist and is created
2016-01-14 16:14:16,434 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0005, dagName=[517206FBA26B43878718C3C106690841/C393404FECF249B4881C36FE8E6EA6BF] lower*upper/(1/1) ...nfigFromScheme/dupeconfig
2016-01-14 16:14:16,438 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0005/
2016-01-14 16:14:16,451 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted tez dag to app master: application_1452787991698_0005, with dag id: dag_1452787991698_0005_1
2016-01-14 16:14:21,078 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0004_01_000002 is : 143
2016-01-14 16:14:28,794 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:12.499, using cpu time: 00:03.130
2016-01-14 16:14:28,891 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testDupeConfigFromScheme/dupeconfig
2016-01-14 16:14:28,923 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:28,923 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:28,960 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.012
2016-01-14 16:14:28,974 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 16:14:28,975 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:14:28,975 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:14:28,975 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:29,024 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:29,025 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:29,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.011
2016-01-14 16:14:29,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-01-14 16:14:29,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:14:29,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 16:14:29,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:29,129 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting
2016-01-14 16:14:29,131 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] parallel execution of flows is enabled: true
2016-01-14 16:14:29,131 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] executing total flows: 2
2016-01-14 16:14:29,131 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] allocating management threads: 2
2016-01-14 16:14:29,132 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: first
2016-01-14 16:14:29,132 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 16:14:29,132 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 16:14:29,135 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/8CE03ADE2A4749EB9B470D270A7DD175/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:29,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 16:14:29,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] source: MultiSourceTap[2:[GlobHfs[/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{ppe[_r]}.txt], GlobHfs[/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/?{owe?}.txt]]]
2016-01-14 16:14:29,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource"]
2016-01-14 16:14:29,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] parallel execution of steps is enabled: true
2016-01-14 16:14:29,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executing total steps: 1
2016-01-14 16:14:29,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] allocating management threads: 1
2016-01-14 16:14:29,158 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...ceGlobHfs/globmultisource
2016-01-14 16:14:29,174 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tez session mode enabled: false
2016-01-14 16:14:29,179 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-01-14 16:14:29,192 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:14:29,193 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0006
2016-01-14 16:14:29,193 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:14:29,203 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/8CE03ADE2A4749EB9B470D270A7DD175/F887D72B5CDC4B57823C38A550CAD0E6/.tez/application_1452787991698_0006 doesn't exist and is created
2016-01-14 16:14:29,263 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0006, dagName=[8CE03ADE2A4749EB9B470D270A7DD175/F887D72B5CDC4B57823C38A550CAD0E6] first/(1/1) ...ceGlobHfs/globmultisource
2016-01-14 16:14:29,266 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0006/
2016-01-14 16:14:29,280 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted tez dag to app master: application_1452787991698_0006, with dag id: dag_1452787991698_0006_1
2016-01-14 16:14:33,824 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0005_01_000002 is : 143
2016-01-14 16:14:42,981 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] completed in: 00:13.824, using cpu time: 00:02.950
2016-01-14 16:14:42,982 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: first
2016-01-14 16:14:42,982 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] starting flow: second
2016-01-14 16:14:42,982 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] at least one sink is marked for delete
2016-01-14 16:14:42,982 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 16:14:43,028 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/4A1A41E482904A75848655F63ED5580A/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:43,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 16:14:43,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource"]
2016-01-14 16:14:43,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultiource2"]
2016-01-14 16:14:43,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] parallel execution of steps is enabled: true
2016-01-14 16:14:43,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executing total steps: 1
2016-01-14 16:14:43,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] allocating management threads: 1
2016-01-14 16:14:43,061 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...ceGlobHfs/globmultiource2
2016-01-14 16:14:43,077 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tez session mode enabled: false
2016-01-14 16:14:43,080 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-01-14 16:14:43,096 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:14:43,097 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0007
2016-01-14 16:14:43,097 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:14:43,108 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/4A1A41E482904A75848655F63ED5580A/E8E7744B86F54179A832F55303999A6C/.tez/application_1452787991698_0007 doesn't exist and is created
2016-01-14 16:14:43,167 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0007, dagName=[4A1A41E482904A75848655F63ED5580A/E8E7744B86F54179A832F55303999A6C] second/(1/1) ...ceGlobHfs/globmultiource2
2016-01-14 16:14:43,170 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0007/
2016-01-14 16:14:43,184 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted tez dag to app master: application_1452787991698_0007, with dag id: dag_1452787991698_0007_1
2016-01-14 16:14:48,014 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0006_01_000002 is : 143
2016-01-14 16:14:49,002 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452787991698_0006_01_000002
2016-01-14 16:14:57,112 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] completed in: 00:14.052, using cpu time: 00:02.830
2016-01-14 16:14:57,112 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second] completed flow: second
2016-01-14 16:14:57,187 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultiource2
2016-01-14 16:14:57,193 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testNestedMultiSourceGlobHfs/globmultisource
2016-01-14 16:14:57,322 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:57,323 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:57,364 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-01-14 16:14:57,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-01-14 16:14:57,382 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:57,382 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:57,382 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:57,470 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/30B0F21ADAC94B538BCCDE20B9863B43/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:57,495 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:14:57,495 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-01-14 16:14:57,495 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResourceForWriteFails/preparewritetapfail"]
2016-01-14 16:14:57,499 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:14:57,499 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:14:57,500 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:14:57,502 ERROR flow.Flow (BaseFlow.java:logError(1469)) - [test] unable to prepare tap for write: hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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:774)
at cascading.tap.hadoop.HadoopTapPlatformTest$7.prepareResourceForWrite(HadoopTapPlatformTest.java:770)
at cascading.flow.planner.BaseFlowStep.prepareResource(BaseFlowStep.java:567)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:549)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:535)
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-01-14 16:14:57,504 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping all jobs
2016-01-14 16:14:57,505 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping: (1/1) ...Fails/preparewritetapfail
2016-01-14 16:14:57,505 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [test] getDagStatus returned null
2016-01-14 16:14:57,505 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopped all jobs
2016-01-14 16:14:57,506 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.011
2016-01-14 16:14:57,507 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testPrepareResourceForWriteFails/preparewritetapfail
2016-01-14 16:14:57,544 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:57,544 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:57,591 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 16:14:57,612 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-01-14 16:14:57,612 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:57,613 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:57,613 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:57,707 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/7BFC06F7B81046C38BA6C84716175E24/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:57,730 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:14:57,730 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: ["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-01-14 16:14:57,730 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testPrepareResourceForReadFails/preparereadtapfail"]
2016-01-14 16:14:57,731 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:14:57,731 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:14:57,731 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:14:57,732 ERROR flow.Flow (BaseFlow.java:logError(1469)) - [test] unable to prepare tap for read: hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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:726)
at cascading.tap.hadoop.HadoopTapPlatformTest$6.prepareResourceForRead(HadoopTapPlatformTest.java:722)
at cascading.flow.planner.BaseFlowStep.prepareResource(BaseFlowStep.java:569)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:549)
at cascading.flow.planner.BaseFlowStep.prepareResources(BaseFlowStep.java:532)
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-01-14 16:14:57,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping all jobs
2016-01-14 16:14:57,734 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping: (1/1) ...dFails/preparereadtapfail
2016-01-14 16:14:57,734 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [test] getDagStatus returned null
2016-01-14 16:14:57,734 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopped all jobs
2016-01-14 16:14:57,734 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.004
2016-01-14 16:14:57,734 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testPrepareResourceForReadFails/preparereadtapfail
2016-01-14 16:14:57,762 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:14:57,762 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:57,802 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.014
2016-01-14 16:14:57,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-01-14 16:14:57,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:57,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:14:57,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:14:57,910 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/D432A9A6984A46D3976DC61DA464F2E2/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:14:57,934 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:14:57,934 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-01-14 16:14:57,934 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResourceFails/committapfail"]
2016-01-14 16:14:57,935 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:14:57,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:14:57,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:14:57,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...sourceFails/committapfail
2016-01-14 16:14:57,950 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tez session mode enabled: false
2016-01-14 16:14:57,953 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-01-14 16:14:57,965 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:14:57,966 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0008
2016-01-14 16:14:57,966 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:14:57,975 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/D432A9A6984A46D3976DC61DA464F2E2/B811E639113C4ACD9E9BB9056D3CD934/.tez/application_1452787991698_0008 doesn't exist and is created
2016-01-14 16:14:58,036 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0008, dagName=[D432A9A6984A46D3976DC61DA464F2E2/B811E639113C4ACD9E9BB9056D3CD934] test/(1/1) ...sourceFails/committapfail
2016-01-14 16:14:58,040 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0008/
2016-01-14 16:14:58,055 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted tez dag to app master: application_1452787991698_0008, with dag id: dag_1452787991698_0008_1
2016-01-14 16:15:02,162 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0007_01_000002 is : 143
2016-01-14 16:15:03,136 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452787991698_0007_01_000002
2016-01-14 16:15:12,077 ERROR flow.Flow (BaseFlow.java:logError(1469)) - [test] unable to commit sink: hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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:400)
at cascading.tap.hadoop.HadoopTapPlatformTest$2.commitResource(HadoopTapPlatformTest.java:396)
at cascading.flow.planner.BaseFlowStep.commitResource(BaseFlowStep.java:613)
at cascading.flow.planner.BaseFlowStep.commitSinks(BaseFlowStep.java:601)
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-01-14 16:15:12,083 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping all jobs
2016-01-14 16:15:12,083 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping: (1/1) ...sourceFails/committapfail
2016-01-14 16:15:12,084 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopped all jobs
2016-01-14 16:15:12,085 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:14.150, using cpu time: 00:03.620
2016-01-14 16:15:12,085 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testCommitResourceFails/committapfail
2016-01-14 16:15:12,158 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:15:12,158 INFO planner.Hadoop2TezPlanner (Hadoop2TezPlanner.java:initialize(149)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:15:12,199 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.017
2016-01-14 16:15:12,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-01-14 16:15:12,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:15:12,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:15:12,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:15:12,301 INFO util.HadoopUtil (HadoopUtil.java:syncPaths(602)) - copying from: file:/opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-tez/3.0.4/561447ee876073bb61fddc52e2ad157f45c8edd/cascading-hadoop2-tez-3.0.4.jar, to: hdfs://localhost:46576/user/teamcity/.staging/3CEC95FB1B4349B1980A564F03BB7CE0/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 16:15:12,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:15:12,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/classes/test/data/apache.10.txt"]
2016-01-14 16:15:12,324 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: ["TextDelimited[['ip', 'count']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testCommitResource/committap"]
2016-01-14 16:15:12,324 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: true
2016-01-14 16:15:12,324 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:15:12,325 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:15:12,325 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...tCommitResource/committap
2016-01-14 16:15:12,353 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tez session mode enabled: false
2016-01-14 16:15:12,357 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-01-14 16:15:12,370 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 16:15:12,371 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452787991698_0009
2016-01-14 16:15:12,371 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:46576/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 16:15:12,379 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:46576/user/teamcity/.staging/3CEC95FB1B4349B1980A564F03BB7CE0/B5562F2687BC4ADCB8C674354B0AFEB7/.tez/application_1452787991698_0009 doesn't exist and is created
2016-01-14 16:15:12,436 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452787991698_0009, dagName=[3CEC95FB1B4349B1980A564F03BB7CE0/B5562F2687BC4ADCB8C674354B0AFEB7] test/(1/1) ...tCommitResource/committap
2016-01-14 16:15:12,639 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:41591/proxy/application_1452787991698_0009/
2016-01-14 16:15:12,657 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted tez dag to app master: application_1452787991698_0009, with dag id: dag_1452787991698_0009_1
2016-01-14 16:15:17,112 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452787991698_0008_01_000002 is : 143
2016-01-14 16:15:18,101 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452787991698_0008_01_000002
2016-01-14 16:15:26,861 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:14.538, using cpu time: 00:03.530
2016-01-14 16:15:26,945 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testCommitResource/committap
2016-01-14 16:15:27,011 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,011 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-01-14 16:15:27,014 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A/part-00000
2016-01-14 16:15:27,029 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,036 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A
2016-01-14 16:15:27,037 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A/_temporary
2016-01-14 16:15:27,053 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,053 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-01-14 16:15:27,057 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B/part-00000
2016-01-14 16:15:27,071 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,079 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B
2016-01-14 16:15:27,080 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B/_temporary
2016-01-14 16:15:27,138 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,138 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-01-14 16:15:27,141 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A/part-00000
2016-01-14 16:15:27,155 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,165 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A
2016-01-14 16:15:27,165 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A/_temporary
2016-01-14 16:15:27,183 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,183 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-01-14 16:15:27,186 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B/part-00000
2016-01-14 16:15:27,198 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,207 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B
2016-01-14 16:15:27,208 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B/_temporary
2016-01-14 16:15:27,224 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,224 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-01-14 16:15:27,228 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden/part-00000
2016-01-14 16:15:27,241 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_002147483647_0000_m_000000_0' - hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/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-01-14 16:15:27,247 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_002147483647_0000_m_000000_0' to hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden
2016-01-14 16:15:27,248 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path hdfs://localhost:46576/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden/_temporary
2016-01-14 16:15:27,263 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles
2016-01-14 16:15:27,273 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles
2016-01-14 16:15:27,280 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/A
2016-01-14 16:15:27,284 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/.hidden
2016-01-14 16:15:27,288 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/hiddenfiles/B
2016-01-14 16:15:27,292 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/A
2016-01-14 16:15:27,296 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output//hadoop2-tez/hadooptapplatform/testChildIdentifiers/multifiles/B