2016-01-14 15:55:17,357 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 15:55:17,390 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.cascade.ParallelCascadePlatformTest, with platform: hadoop2-tez
2016-01-14 15:55:17,423 INFO tez.Hadoop2TezPlatform (Hadoop2TezPlatform.java:setUp(164)) - using cluster
2016-01-14 15:55:18,121 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 15:55:19,065 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 15:55:19,576 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 15:55:22,432 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 15:55:22,638 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(121)) - Set TEZ-LIB-URI to: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:55:22,644 INFO test.MiniTezCluster (MiniTezCluster.java:serviceInit(152)) - mkdir: hdfs://localhost:36271/apps_staging_dir
2016-01-14 15:55:23,027 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 15:55:23,114 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 15:55:23,160 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 15:55:23,206 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 15:55:23,211 INFO test.MiniTezCluster (MiniTezCluster.java:serviceStart(186)) - Starting MiniTezCluster
2016-01-14 15:55:28,869 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 15:55:29,332 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 15:55:29,446 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:55:29,446 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 15:55:29,516 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 4B2A5CDE97B5443385F156FBB7F88D54
2016-01-14 15:55:29,647 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.061
2016-01-14 15:55:29,658 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.073
2016-01-14 15:55:29,660 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:29,660 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:29,661 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:55:29,866 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopping all flows
2016-01-14 15:55:29,866 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 15:55:29,866 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopped all flows
2016-01-14 15:55:29,867 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] starting
2016-01-14 15:55:29,903 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:55:29,903 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 15:55:29,965 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-01-14 15:55:29,979 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-01-14 15:55:29,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:29,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:29,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:55:30,032 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting
2016-01-14 15:55:30,035 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] parallel execution of flows is enabled: false
2016-01-14 15:55:30,035 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] executing total flows: 1
2016-01-14 15:55:30,035 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] allocating management threads: 1
2016-01-14 15:55:30,036 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting flow: race-50/first-nondeterministic
2016-01-14 15:55:30,037 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] at least one sink is marked for delete
2016-01-14 15:55:30,037 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:55:30,053 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:36271/user/teamcity/.staging/BA3555A45AFF445E82F6A9750DC85080/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:55:30,082 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping all flows
2016-01-14 15:55:30,083 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping flow: race-50/first-nondeterministic
2016-01-14 15:55:30,111 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopping all jobs
2016-01-14 15:55:30,112 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 15:55:30,112 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [race-50/first-nondeter...] getDagStatus returned null
2016-01-14 15:55:30,112 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopped all jobs
2016-01-14 15:55:30,113 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopped all flows
2016-01-14 15:55:30,113 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutting down flow executor
2016-01-14 15:55:30,117 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] completed in: 16814:15:55:30.111
2016-01-14 15:55:30,117 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] completed flow: race-50/first-nondeterministic
2016-01-14 15:55:30,117 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutdown complete
2016-01-14 15:55:30,158 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:55:30,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 15:55:30,211 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 15:55:30,223 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-01-14 15:55:30,224 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:30,224 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:30,225 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:55:30,296 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting
2016-01-14 15:55:30,298 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:55:30,298 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] executing total flows: 1
2016-01-14 15:55:30,299 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] allocating management threads: 1
2016-01-14 15:55:30,300 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting flow: race-100/first-nondeterministic
2016-01-14 15:55:30,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] at least one sink is marked for delete
2016-01-14 15:55:30,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:55:30,305 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:36271/user/teamcity/.staging/A047F26EE6C24867AC79740FE469A54B/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:55:30,341 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] starting
2016-01-14 15:55:30,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:55:30,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic"]
2016-01-14 15:55:30,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:55:30,343 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] executing total steps: 1
2016-01-14 15:55:30,343 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] allocating management threads: 1
2016-01-14 15:55:30,344 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 15:55:30,359 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] tez session mode enabled: false
2016-01-14 15:55:30,378 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 15:55:30,396 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping all flows
2016-01-14 15:55:30,397 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping flow: race-100/first-nondeterministic
2016-01-14 15:55:30,397 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopping all jobs
2016-01-14 15:55:30,398 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 15:55:30,398 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [race-100/first-nondete...] getDagStatus returned null
2016-01-14 15:55:30,453 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:55:30,455 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopped all jobs
2016-01-14 15:55:30,455 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] shutting down job executor
2016-01-14 15:55:30,486 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0001
2016-01-14 15:55:30,487 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:55:30,504 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/A047F26EE6C24867AC79740FE469A54B/C6D335307B424E03BE663702B3C2FBB6/.tez/application_1452786923212_0001 doesn't exist and is created
2016-01-14 15:55:30,667 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0001, dagName=[A047F26EE6C24867AC79740FE469A54B/C6D335307B424E03BE663702B3C2FBB6] race-100/first-nondeterministic/(1/1) ...00/first-nondeterministic
2016-01-14 15:55:30,958 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0001/
2016-01-14 15:55:30,996 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] submitted tez dag to app master: application_1452786923212_0001, with dag id: dag_1452786923212_0001_1
2016-01-14 15:55:31,014 INFO client.TimelineReaderFactory (TimelineReaderFactory.java:tokenDelegationSupported(381)) - Could not find class required for token delegation, will fallback to pseudo auth
2016-01-14 15:55:31,020 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] shutdown complete
2016-01-14 15:55:31,021 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopped all flows
2016-01-14 15:55:31,021 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutting down flow executor
2016-01-14 15:55:31,024 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] completed in: 00:00.056
2016-01-14 15:55:31,024 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] completed flow: race-100/first-nondeterministic
2016-01-14 15:55:31,024 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutdown complete
2016-01-14 15:55:31,068 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:55:31,069 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 15:55:31,153 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-01-14 15:55:31,159 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.049
2016-01-14 15:55:31,163 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:31,163 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:31,164 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:55:31,236 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting
2016-01-14 15:55:31,243 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:55:31,244 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] executing total flows: 1
2016-01-14 15:55:31,244 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] allocating management threads: 1
2016-01-14 15:55:31,245 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting flow: race-150/first-nondeterministic
2016-01-14 15:55:31,246 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] at least one sink is marked for delete
2016-01-14 15:55:31,246 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:55:31,256 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:36271/user/teamcity/.staging/514626CC7082410582B932AB60CFD2C9/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:55:31,304 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] starting
2016-01-14 15:55:31,306 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:55:31,306 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic"]
2016-01-14 15:55:31,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:55:31,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] executing total steps: 1
2016-01-14 15:55:31,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] allocating management threads: 1
2016-01-14 15:55:31,310 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 15:55:31,361 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] tez session mode enabled: false
2016-01-14 15:55:31,367 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 15:55:31,386 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping all flows
2016-01-14 15:55:31,387 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping flow: race-150/first-nondeterministic
2016-01-14 15:55:31,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopping all jobs
2016-01-14 15:55:31,389 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 15:55:31,390 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [race-150/first-nondete...] getDagStatus returned null
2016-01-14 15:55:31,398 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:55:31,399 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopped all jobs
2016-01-14 15:55:31,400 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] shutting down job executor
2016-01-14 15:55:31,402 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0002
2016-01-14 15:55:31,402 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:55:31,430 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/514626CC7082410582B932AB60CFD2C9/A25B6118090A4C10ADCBBB665039448E/.tez/application_1452786923212_0002 doesn't exist and is created
2016-01-14 15:55:31,570 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0002, dagName=[514626CC7082410582B932AB60CFD2C9/A25B6118090A4C10ADCBBB665039448E] race-150/first-nondeterministic/(1/1) ...50/first-nondeterministic
2016-01-14 15:55:31,576 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0002/
2016-01-14 15:55:31,592 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] submitted tez dag to app master: application_1452786923212_0002, with dag id: dag_1452786923212_0002_1
2016-01-14 15:55:31,601 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] shutdown complete
2016-01-14 15:55:31,601 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopped all flows
2016-01-14 15:55:31,601 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutting down flow executor
2016-01-14 15:55:31,604 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] completed in: 00:00.084
2016-01-14 15:55:31,605 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] completed flow: race-150/first-nondeterministic
2016-01-14 15:55:31,605 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutdown complete
2016-01-14 15:55:31,643 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:55:31,643 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 15:55:31,713 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 15:55:31,727 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.036
2016-01-14 15:55:31,729 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:31,729 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:31,730 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:55:31,776 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting
2016-01-14 15:55:31,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:55:31,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] executing total flows: 1
2016-01-14 15:55:31,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] allocating management threads: 1
2016-01-14 15:55:31,778 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting flow: race-200/first-nondeterministic
2016-01-14 15:55:31,778 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] at least one sink is marked for delete
2016-01-14 15:55:31,780 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:55:31,786 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:36271/user/teamcity/.staging/180A00F68F96424585918498570058B3/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:55:31,825 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] starting
2016-01-14 15:55:31,825 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:55:31,825 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic"]
2016-01-14 15:55:31,826 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:55:31,826 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] executing total steps: 1
2016-01-14 15:55:31,826 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] allocating management threads: 1
2016-01-14 15:55:31,828 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 15:55:31,847 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] tez session mode enabled: false
2016-01-14 15:55:31,851 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 15:55:31,873 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:55:31,875 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0003
2016-01-14 15:55:31,875 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:55:31,895 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/180A00F68F96424585918498570058B3/BDD3B762A810494BB9FC23C93659ED7E/.tez/application_1452786923212_0003 doesn't exist and is created
2016-01-14 15:55:31,976 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping all flows
2016-01-14 15:55:31,978 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping flow: race-200/first-nondeterministic
2016-01-14 15:55:31,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopping all jobs
2016-01-14 15:55:31,979 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 15:55:31,979 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [race-200/first-nondete...] getDagStatus returned null
2016-01-14 15:55:31,989 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0003, dagName=[180A00F68F96424585918498570058B3/BDD3B762A810494BB9FC23C93659ED7E] race-200/first-nondeterministic/(1/1) ...00/first-nondeterministic
2016-01-14 15:55:31,995 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0003/
2016-01-14 15:55:32,014 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopped all jobs
2016-01-14 15:55:32,014 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] submitted tez dag to app master: application_1452786923212_0003, with dag id: dag_1452786923212_0003_1
2016-01-14 15:55:32,014 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] shutting down job executor
2016-01-14 15:55:32,020 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] shutdown complete
2016-01-14 15:55:32,021 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopped all flows
2016-01-14 15:55:32,021 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutting down flow executor
2016-01-14 15:55:32,025 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] completed in: 00:00.153
2016-01-14 15:55:32,025 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] completed flow: race-200/first-nondeterministic
2016-01-14 15:55:32,025 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutdown complete
2016-01-14 15:55:32,055 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:55:32,056 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 15:55:32,122 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 15:55:32,134 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-01-14 15:55:32,134 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:32,135 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:55:32,135 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:55:32,169 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting
2016-01-14 15:55:32,170 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:55:32,170 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] executing total flows: 1
2016-01-14 15:55:32,170 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] allocating management threads: 1
2016-01-14 15:55:32,173 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting flow: race-250/first-nondeterministic
2016-01-14 15:55:32,173 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] at least one sink is marked for delete
2016-01-14 15:55:32,174 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:55:32,179 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:36271/user/teamcity/.staging/81AEF020F1384B29B76D5161411AE0C8/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:55:32,215 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] starting
2016-01-14 15:55:32,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:55:32,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic"]
2016-01-14 15:55:32,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:55:32,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] executing total steps: 1
2016-01-14 15:55:32,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] allocating management threads: 1
2016-01-14 15:55:32,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 15:55:32,236 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] tez session mode enabled: false
2016-01-14 15:55:32,242 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 15:55:32,259 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:55:32,260 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0004
2016-01-14 15:55:32,261 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:55:32,292 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/81AEF020F1384B29B76D5161411AE0C8/C3588E85780E4E75A3AC75047A4DA412/.tez/application_1452786923212_0004 doesn't exist and is created
2016-01-14 15:55:32,393 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0004, dagName=[81AEF020F1384B29B76D5161411AE0C8/C3588E85780E4E75A3AC75047A4DA412] race-250/first-nondeterministic/(1/1) ...50/first-nondeterministic
2016-01-14 15:55:32,399 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0004/
2016-01-14 15:55:32,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] submitted tez dag to app master: application_1452786923212_0004, with dag id: dag_1452786923212_0004_1
2016-01-14 15:55:32,419 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping all flows
2016-01-14 15:55:32,420 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping flow: race-250/first-nondeterministic
2016-01-14 15:55:32,420 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopping all jobs
2016-01-14 15:55:32,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 15:55:32,427 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopped all jobs
2016-01-14 15:55:32,427 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] shutting down job executor
2016-01-14 15:55:32,431 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 15:55:33,438 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 77
2016-01-14 15:55:34,441 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 152
2016-01-14 15:55:35,444 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 226
2016-01-14 15:55:36,450 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 301
2016-01-14 15:55:37,457 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 376
2016-01-14 15:55:38,468 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 450
2016-01-14 15:55:39,470 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 523
2016-01-14 15:55:40,486 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 604
2016-01-14 15:55:41,500 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 683
2016-01-14 15:55:42,504 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 755
2016-01-14 15:55:43,510 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 836
2016-01-14 15:55:44,519 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 917
2016-01-14 15:55:45,521 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 994
2016-01-14 15:55:46,529 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1075
2016-01-14 15:55:47,540 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1156
2016-01-14 15:55:48,545 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1237
2016-01-14 15:55:49,552 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1320
2016-01-14 15:55:50,564 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1405
2016-01-14 15:55:50,929 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0001_01_000002 is : 143
2016-01-14 15:55:51,568 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1489
2016-01-14 15:55:52,578 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1574
2016-01-14 15:55:53,580 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1658
2016-01-14 15:55:54,138 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0002_01_000002 is : 143
2016-01-14 15:55:54,584 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1740
2016-01-14 15:55:55,591 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1821
2016-01-14 15:55:56,601 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1901
2016-01-14 15:55:57,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1982
2016-01-14 15:55:58,622 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2061
2016-01-14 15:55:59,631 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2141
2016-01-14 15:56:00,632 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2222
2016-01-14 15:56:01,646 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2306
2016-01-14 15:56:02,647 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2346
2016-01-14 15:56:03,660 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2398
2016-01-14 15:56:04,667 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2475
2016-01-14 15:56:05,678 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2553
2016-01-14 15:56:06,688 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2628
2016-01-14 15:56:07,695 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2708
2016-01-14 15:56:08,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 2791
2016-01-14 15:56:09,496 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] shutdown complete
2016-01-14 15:56:09,497 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopped all flows
2016-01-14 15:56:09,497 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutting down flow executor
2016-01-14 15:56:09,517 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 15:56:09,517 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] completed in: 00:00.205
2016-01-14 15:56:09,517 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] completed flow: race-250/first-nondeterministic
2016-01-14 15:56:09,517 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutdown complete
2016-01-14 15:56:09,548 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:56:09,548 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 15:56:09,598 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.011
2016-01-14 15:56:09,615 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 15:56:09,616 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:09,616 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:09,617 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:56:09,660 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting
2016-01-14 15:56:09,661 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:56:09,661 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] executing total flows: 1
2016-01-14 15:56:09,662 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] allocating management threads: 1
2016-01-14 15:56:09,662 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting flow: race-300/first-nondeterministic
2016-01-14 15:56:09,662 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] at least one sink is marked for delete
2016-01-14 15:56:09,662 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:56:09,669 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:36271/user/teamcity/.staging/D7F4F2D378E24285B7F89921A13ABC1F/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:56:09,692 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] starting
2016-01-14 15:56:09,693 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:56:09,693 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic"]
2016-01-14 15:56:09,693 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:56:09,693 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] executing total steps: 1
2016-01-14 15:56:09,693 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] allocating management threads: 1
2016-01-14 15:56:09,694 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 15:56:09,709 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] tez session mode enabled: false
2016-01-14 15:56:09,713 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 15:56:09,726 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:56:09,727 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0005
2016-01-14 15:56:09,727 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:56:09,743 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/D7F4F2D378E24285B7F89921A13ABC1F/A8AD2721A79B496A8FE3DEF9091A872B/.tez/application_1452786923212_0005 doesn't exist and is created
2016-01-14 15:56:09,806 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0005, dagName=[D7F4F2D378E24285B7F89921A13ABC1F/A8AD2721A79B496A8FE3DEF9091A872B] race-300/first-nondeterministic/(1/1) ...00/first-nondeterministic
2016-01-14 15:56:09,809 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0005/
2016-01-14 15:56:09,823 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] submitted tez dag to app master: application_1452786923212_0005, with dag id: dag_1452786923212_0005_1
2016-01-14 15:56:09,960 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping all flows
2016-01-14 15:56:09,962 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping flow: race-300/first-nondeterministic
2016-01-14 15:56:09,962 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopping all jobs
2016-01-14 15:56:09,962 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 15:56:09,966 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopped all jobs
2016-01-14 15:56:09,966 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] shutting down job executor
2016-01-14 15:56:09,969 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 15:56:10,981 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 88
2016-01-14 15:56:11,253 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0003_01_000002 is : 143
2016-01-14 15:56:11,992 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 175
2016-01-14 15:56:12,997 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 262
2016-01-14 15:56:14,003 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 347
2016-01-14 15:56:14,601 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0004_01_000002 is : 143
2016-01-14 15:56:15,010 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 432
2016-01-14 15:56:16,019 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 517
2016-01-14 15:56:17,026 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 601
2016-01-14 15:56:18,031 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 686
2016-01-14 15:56:19,047 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 739
2016-01-14 15:56:20,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 808
2016-01-14 15:56:21,069 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 890
2016-01-14 15:56:22,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 971
2016-01-14 15:56:23,082 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1053
2016-01-14 15:56:24,093 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1135
2016-01-14 15:56:25,101 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1219
2016-01-14 15:56:26,106 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 1310
2016-01-14 15:56:26,156 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] shutdown complete
2016-01-14 15:56:26,156 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopped all flows
2016-01-14 15:56:26,157 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutting down flow executor
2016-01-14 15:56:26,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] completed in: 00:00.270
2016-01-14 15:56:26,158 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] completed flow: race-300/first-nondeterministic
2016-01-14 15:56:26,158 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutdown complete
2016-01-14 15:56:26,192 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:56:26,193 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 15:56:26,241 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.014
2016-01-14 15:56:26,256 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-01-14 15:56:26,257 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:26,257 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:26,257 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:56:26,283 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting
2016-01-14 15:56:26,284 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:56:26,284 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] executing total flows: 1
2016-01-14 15:56:26,284 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] allocating management threads: 1
2016-01-14 15:56:26,285 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting flow: race-350/first-nondeterministic
2016-01-14 15:56:26,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] at least one sink is marked for delete
2016-01-14 15:56:26,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:56:26,289 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:36271/user/teamcity/.staging/F6C45210244F4E2BB6BF7710DC0EBF83/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:56:26,310 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] starting
2016-01-14 15:56:26,310 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:56:26,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic"]
2016-01-14 15:56:26,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:56:26,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] executing total steps: 1
2016-01-14 15:56:26,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] allocating management threads: 1
2016-01-14 15:56:26,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 15:56:26,326 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] tez session mode enabled: false
2016-01-14 15:56:26,331 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 15:56:26,344 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:56:26,345 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0006
2016-01-14 15:56:26,346 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:56:26,357 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/F6C45210244F4E2BB6BF7710DC0EBF83/D7EF9F0CA0C14B3EA855DF4D10CDA9F5/.tez/application_1452786923212_0006 doesn't exist and is created
2016-01-14 15:56:26,419 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0006, dagName=[F6C45210244F4E2BB6BF7710DC0EBF83/D7EF9F0CA0C14B3EA855DF4D10CDA9F5] race-350/first-nondeterministic/(1/1) ...50/first-nondeterministic
2016-01-14 15:56:26,422 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0006/
2016-01-14 15:56:26,436 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] submitted tez dag to app master: application_1452786923212_0006, with dag id: dag_1452786923212_0006_1
2016-01-14 15:56:26,633 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping all flows
2016-01-14 15:56:26,634 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping flow: race-350/first-nondeterministic
2016-01-14 15:56:26,634 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopping all jobs
2016-01-14 15:56:26,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 15:56:26,640 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 15:56:26,641 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopped all jobs
2016-01-14 15:56:26,642 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] shutting down job executor
2016-01-14 15:56:27,652 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 87
2016-01-14 15:56:28,656 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 172
2016-01-14 15:56:29,663 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 259
2016-01-14 15:56:30,670 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 345
2016-01-14 15:56:31,274 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0005_01_000002 is : 143
2016-01-14 15:56:31,676 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 430
2016-01-14 15:56:32,256 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0005_01_000002
2016-01-14 15:56:32,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 480
2016-01-14 15:56:33,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 548
2016-01-14 15:56:34,697 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 631
2016-01-14 15:56:35,707 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 713
2016-01-14 15:56:36,714 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 796
2016-01-14 15:56:37,725 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 878
2016-01-14 15:56:38,732 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 964
2016-01-14 15:56:39,715 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] shutdown complete
2016-01-14 15:56:39,715 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopped all flows
2016-01-14 15:56:39,715 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutting down flow executor
2016-01-14 15:56:39,716 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] completed in: 00:00.324
2016-01-14 15:56:39,716 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] completed flow: race-350/first-nondeterministic
2016-01-14 15:56:39,716 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutdown complete
2016-01-14 15:56:39,753 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:56:39,753 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 15:56:39,811 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-01-14 15:56:39,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-01-14 15:56:39,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:39,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:39,821 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:56:39,848 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting
2016-01-14 15:56:39,849 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:56:39,849 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] executing total flows: 1
2016-01-14 15:56:39,849 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] allocating management threads: 1
2016-01-14 15:56:39,850 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting flow: race-400/first-nondeterministic
2016-01-14 15:56:39,850 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] at least one sink is marked for delete
2016-01-14 15:56:39,850 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:56:39,853 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:36271/user/teamcity/.staging/90431E60751B43BCABC299E1B3D70CD6/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:56:39,874 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] starting
2016-01-14 15:56:39,874 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:56:39,874 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic"]
2016-01-14 15:56:39,875 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:56:39,875 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] executing total steps: 1
2016-01-14 15:56:39,875 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] allocating management threads: 1
2016-01-14 15:56:39,876 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 15:56:39,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] tez session mode enabled: false
2016-01-14 15:56:39,894 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 15:56:39,907 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:56:39,908 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0007
2016-01-14 15:56:39,909 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:56:39,938 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/90431E60751B43BCABC299E1B3D70CD6/B7F308B9974948C29EBADFD409DE5BB8/.tez/application_1452786923212_0007 doesn't exist and is created
2016-01-14 15:56:39,996 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0007, dagName=[90431E60751B43BCABC299E1B3D70CD6/B7F308B9974948C29EBADFD409DE5BB8] race-400/first-nondeterministic/(1/1) ...00/first-nondeterministic
2016-01-14 15:56:39,999 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0007/
2016-01-14 15:56:40,014 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] submitted tez dag to app master: application_1452786923212_0007, with dag id: dag_1452786923212_0007_1
2016-01-14 15:56:40,248 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping all flows
2016-01-14 15:56:40,249 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping flow: race-400/first-nondeterministic
2016-01-14 15:56:40,249 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopping all jobs
2016-01-14 15:56:40,250 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 15:56:40,255 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopped all jobs
2016-01-14 15:56:40,255 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] shutting down job executor
2016-01-14 15:56:40,258 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 15:56:41,262 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 87
2016-01-14 15:56:42,266 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 174
2016-01-14 15:56:43,273 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 261
2016-01-14 15:56:44,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 347
2016-01-14 15:56:44,825 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0006_01_000002 is : 143
2016-01-14 15:56:45,285 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 434
2016-01-14 15:56:45,811 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0006_01_000002
2016-01-14 15:56:46,332 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 481
2016-01-14 15:56:47,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 556
2016-01-14 15:56:48,355 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 639
2016-01-14 15:56:49,364 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 721
2016-01-14 15:56:50,374 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 806
2016-01-14 15:56:51,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 896
2016-01-14 15:56:51,534 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] shutdown complete
2016-01-14 15:56:51,535 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopped all flows
2016-01-14 15:56:51,535 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutting down flow executor
2016-01-14 15:56:51,536 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] completed in: 00:00.375
2016-01-14 15:56:51,536 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] completed flow: race-400/first-nondeterministic
2016-01-14 15:56:51,537 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutdown complete
2016-01-14 15:56:51,572 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:56:51,573 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 15:56:51,625 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-01-14 15:56:51,641 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-01-14 15:56:51,642 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:51,642 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:56:51,642 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:56:51,691 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting
2016-01-14 15:56:51,692 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:56:51,693 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] executing total flows: 1
2016-01-14 15:56:51,693 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] allocating management threads: 1
2016-01-14 15:56:51,693 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting flow: race-450/first-nondeterministic
2016-01-14 15:56:51,694 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] at least one sink is marked for delete
2016-01-14 15:56:51,694 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:56:51,697 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:36271/user/teamcity/.staging/9CF30F3D78574648BDB148341A7E5B51/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:56:51,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] starting
2016-01-14 15:56:51,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:56:51,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic"]
2016-01-14 15:56:51,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:56:51,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] executing total steps: 1
2016-01-14 15:56:51,724 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] allocating management threads: 1
2016-01-14 15:56:51,726 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 15:56:51,742 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] tez session mode enabled: false
2016-01-14 15:56:51,745 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 15:56:51,759 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:56:51,759 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0008
2016-01-14 15:56:51,760 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:56:51,768 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/9CF30F3D78574648BDB148341A7E5B51/EC2E41EF856D4D83A295548C34A8E38B/.tez/application_1452786923212_0008 doesn't exist and is created
2016-01-14 15:56:51,826 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0008, dagName=[9CF30F3D78574648BDB148341A7E5B51/EC2E41EF856D4D83A295548C34A8E38B] race-450/first-nondeterministic/(1/1) ...50/first-nondeterministic
2016-01-14 15:56:51,830 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0008/
2016-01-14 15:56:51,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] submitted tez dag to app master: application_1452786923212_0008, with dag id: dag_1452786923212_0008_1
2016-01-14 15:56:52,141 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping all flows
2016-01-14 15:56:52,143 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping flow: race-450/first-nondeterministic
2016-01-14 15:56:52,143 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopping all jobs
2016-01-14 15:56:52,144 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 15:56:52,147 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopped all jobs
2016-01-14 15:56:52,147 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] shutting down job executor
2016-01-14 15:56:52,153 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 15:56:53,165 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 90
2016-01-14 15:56:54,174 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 179
2016-01-14 15:56:55,176 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 266
2016-01-14 15:56:56,187 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 355
2016-01-14 15:56:56,699 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0007_01_000002 is : 143
2016-01-14 15:56:57,198 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 444
2016-01-14 15:56:58,246 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 491
2016-01-14 15:56:59,255 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 567
2016-01-14 15:57:00,258 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 649
2016-01-14 15:57:01,263 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 731
2016-01-14 15:57:02,268 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 813
2016-01-14 15:57:03,278 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 893
2016-01-14 15:57:04,283 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 974
2016-01-14 15:57:05,138 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] shutdown complete
2016-01-14 15:57:05,140 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopped all flows
2016-01-14 15:57:05,139 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] completed in: 00:00.420
2016-01-14 15:57:05,140 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] completed flow: race-450/first-nondeterministic
2016-01-14 15:57:05,140 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutting down flow executor
2016-01-14 15:57:05,141 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutdown complete
2016-01-14 15:57:05,179 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:57:05,179 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 15:57:05,228 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.011
2016-01-14 15:57:05,239 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 15:57:05,240 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:05,241 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:05,241 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:57:05,267 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting
2016-01-14 15:57:05,268 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 15:57:05,269 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] executing total flows: 1
2016-01-14 15:57:05,269 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] allocating management threads: 1
2016-01-14 15:57:05,269 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting flow: race-500/first-nondeterministic
2016-01-14 15:57:05,270 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] at least one sink is marked for delete
2016-01-14 15:57:05,270 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:57:05,272 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:36271/user/teamcity/.staging/867F95FA58864603B30B0FDD6145C190/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:57:05,304 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] starting
2016-01-14 15:57:05,304 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] 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/ips.20.txt"]
2016-01-14 15:57:05,305 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic"]
2016-01-14 15:57:05,305 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 15:57:05,305 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] executing total steps: 1
2016-01-14 15:57:05,305 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] allocating management threads: 1
2016-01-14 15:57:05,306 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 15:57:05,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] tez session mode enabled: false
2016-01-14 15:57:05,326 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 15:57:05,340 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:57:05,340 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0009
2016-01-14 15:57:05,341 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:57:05,350 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/867F95FA58864603B30B0FDD6145C190/AE8182A5F9204DB0A8DC6A4B06246709/.tez/application_1452786923212_0009 doesn't exist and is created
2016-01-14 15:57:05,408 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0009, dagName=[867F95FA58864603B30B0FDD6145C190/AE8182A5F9204DB0A8DC6A4B06246709] race-500/first-nondeterministic/(1/1) ...00/first-nondeterministic
2016-01-14 15:57:05,612 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0009/
2016-01-14 15:57:05,625 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] submitted tez dag to app master: application_1452786923212_0009, with dag id: dag_1452786923212_0009_1
2016-01-14 15:57:05,767 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping all flows
2016-01-14 15:57:05,768 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping flow: race-500/first-nondeterministic
2016-01-14 15:57:05,768 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopping all jobs
2016-01-14 15:57:05,768 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 15:57:05,771 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopped all jobs
2016-01-14 15:57:05,771 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] shutting down job executor
2016-01-14 15:57:05,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 15:57:06,785 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 90
2016-01-14 15:57:07,787 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 179
2016-01-14 15:57:08,789 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 268
2016-01-14 15:57:09,792 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 356
2016-01-14 15:57:10,258 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0008_01_000002 is : 143
2016-01-14 15:57:10,794 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 444
2016-01-14 15:57:11,243 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0008_01_000002
2016-01-14 15:57:11,809 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 486
2016-01-14 15:57:12,822 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 562
2016-01-14 15:57:13,831 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 645
2016-01-14 15:57:14,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 727
2016-01-14 15:57:15,840 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 810
2016-01-14 15:57:16,841 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 892
2016-01-14 15:57:17,844 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] did not capture all completed node details, will retry in 00:00.010, prior retries: 979
2016-01-14 15:57:18,608 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] shutdown complete
2016-01-14 15:57:18,609 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopped all flows
2016-01-14 15:57:18,609 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutting down flow executor
2016-01-14 15:57:18,611 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] completed in: 00:00.464
2016-01-14 15:57:18,611 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] completed flow: race-500/first-nondeterministic
2016-01-14 15:57:18,611 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutdown complete
2016-01-14 15:57:18,612 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/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic
2016-01-14 15:57:18,614 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/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic
2016-01-14 15:57:18,626 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/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic
2016-01-14 15:57:18,633 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/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic
2016-01-14 15:57:18,639 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/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic
2016-01-14 15:57:18,645 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/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic
2016-01-14 15:57:18,651 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/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic
2016-01-14 15:57:18,657 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/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic
2016-01-14 15:57:18,664 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/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic
2016-01-14 15:57:18,670 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/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic
2016-01-14 15:57:18,680 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/parallelcascadeplatform/testCascadeRaceCondition/race-0/first-nondeterministic
2016-01-14 15:57:18,725 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:57:18,725 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 15:57:18,763 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.011
2016-01-14 15:57:18,772 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.020
2016-01-14 15:57:18,773 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:18,773 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:18,773 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:57:18,823 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:57:18,824 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 15:57:18,865 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-01-14 15:57:18,871 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 15:57:18,872 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:18,872 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:18,873 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:57:18,922 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:57:18,922 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 15:57:18,964 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.017
2016-01-14 15:57:18,971 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-01-14 15:57:18,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:18,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:18,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:57:19,020 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:57:19,020 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 15:57:19,063 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.017
2016-01-14 15:57:19,070 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 15:57:19,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:19,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 15:57:19,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:57:19,122 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 15:57:19,122 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 15:57:19,175 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executed rule registry: NoHashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 15:57:19,186 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executed rule registry: HashJoinHadoop2TezRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-01-14 15:57:19,187 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: NoHashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 3
2016-01-14 15:57:19,187 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: HashJoinHadoop2TezRuleRegistry, supports assembly with steps: 1, nodes: 3
2016-01-14 15:57:19,187 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: NoHashJoinHadoop2TezRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 15:57:19,320 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting
2016-01-14 15:57:19,321 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] parallel execution of flows is enabled: true
2016-01-14 15:57:19,321 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] executing total flows: 5
2016-01-14 15:57:19,322 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] allocating management threads: 5
2016-01-14 15:57:19,322 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first2
2016-01-14 15:57:19,322 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] at least one sink is marked for delete
2016-01-14 15:57:19,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:57:19,323 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first1
2016-01-14 15:57:19,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] at least one sink is marked for delete
2016-01-14 15:57:19,324 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:57:19,325 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:36271/user/teamcity/.staging/15DD7EBE81924527A81E0C9E84AC8127/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:57:19,332 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:36271/user/teamcity/.staging/337C3BE27A14430995AE497D86F73FE9/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:57:19,366 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] starting
2016-01-14 15:57:19,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] 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/ips.20.txt"]
2016-01-14 15:57:19,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/first2"]
2016-01-14 15:57:19,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] parallel execution of steps is enabled: true
2016-01-14 15:57:19,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] executing total steps: 1
2016-01-14 15:57:19,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] allocating management threads: 1
2016-01-14 15:57:19,369 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] starting step: (1/1) ...atform/testCascade/first2
2016-01-14 15:57:19,372 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] starting
2016-01-14 15:57:19,373 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] 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/ips.20.txt"]
2016-01-14 15:57:19,373 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/first1"]
2016-01-14 15:57:19,373 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] parallel execution of steps is enabled: true
2016-01-14 15:57:19,373 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] executing total steps: 1
2016-01-14 15:57:19,374 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] allocating management threads: 1
2016-01-14 15:57:19,375 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] starting step: (1/1) ...atform/testCascade/first1
2016-01-14 15:57:19,386 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] tez session mode enabled: false
2016-01-14 15:57:19,389 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 15:57:19,389 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] tez session mode enabled: false
2016-01-14 15:57:19,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 15:57:19,402 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:57:19,403 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0010
2016-01-14 15:57:19,403 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:57:19,407 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:57:19,408 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0011
2016-01-14 15:57:19,408 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:57:19,414 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/15DD7EBE81924527A81E0C9E84AC8127/B83C6B771594444AB82B918492C75A63/.tez/application_1452786923212_0010 doesn't exist and is created
2016-01-14 15:57:19,428 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/337C3BE27A14430995AE497D86F73FE9/B886FC2B83094E1AB06320CF94C6B949/.tez/application_1452786923212_0011 doesn't exist and is created
2016-01-14 15:57:19,493 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0010, dagName=[15DD7EBE81924527A81E0C9E84AC8127/B83C6B771594444AB82B918492C75A63] first2/(1/1) ...atform/testCascade/first2
2016-01-14 15:57:19,504 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0011, dagName=[337C3BE27A14430995AE497D86F73FE9/B886FC2B83094E1AB06320CF94C6B949] first1/(1/1) ...atform/testCascade/first1
2016-01-14 15:57:19,507 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0011/
2016-01-14 15:57:19,520 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] submitted tez dag to app master: application_1452786923212_0011, with dag id: dag_1452786923212_0011_1
2016-01-14 15:57:19,698 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0010/
2016-01-14 15:57:19,712 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] submitted tez dag to app master: application_1452786923212_0010, with dag id: dag_1452786923212_0010_1
2016-01-14 15:57:23,728 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0009_01_000002 is : 143
2016-01-14 15:57:24,713 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0009_01_000002
2016-01-14 15:57:34,656 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] completed in: 00:15.288, using cpu time: 00:03.050
2016-01-14 15:57:34,656 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first2
2016-01-14 15:57:34,656 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second2
2016-01-14 15:57:34,657 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] at least one sink is marked for delete
2016-01-14 15:57:34,657 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:57:34,660 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:36271/user/teamcity/.staging/2D4ACE62A9374C2AA17D466CE992F2BD/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:57:34,682 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] starting
2016-01-14 15:57:34,683 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/first2"]
2016-01-14 15:57:34,683 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/second2"]
2016-01-14 15:57:34,683 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] parallel execution of steps is enabled: true
2016-01-14 15:57:34,683 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] executing total steps: 1
2016-01-14 15:57:34,683 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] allocating management threads: 1
2016-01-14 15:57:34,684 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] starting step: (1/1) ...tform/testCascade/second2
2016-01-14 15:57:34,699 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] tez session mode enabled: false
2016-01-14 15:57:34,702 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 15:57:34,717 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:57:34,718 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0012
2016-01-14 15:57:34,719 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:57:34,728 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/2D4ACE62A9374C2AA17D466CE992F2BD/B25BAFB9907C4006A589E79BB945EDFC/.tez/application_1452786923212_0012 doesn't exist and is created
2016-01-14 15:57:34,790 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0012, dagName=[2D4ACE62A9374C2AA17D466CE992F2BD/B25BAFB9907C4006A589E79BB945EDFC] second2/(1/1) ...tform/testCascade/second2
2016-01-14 15:57:34,793 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0012/
2016-01-14 15:57:34,812 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] submitted tez dag to app master: application_1452786923212_0012, with dag id: dag_1452786923212_0012_1
2016-01-14 15:57:39,670 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0010_01_000002 is : 143
2016-01-14 15:57:40,707 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] completed in: 00:21.334, using cpu time: 00:03.120
2016-01-14 15:57:40,707 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first1
2016-01-14 15:57:40,708 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second1
2016-01-14 15:57:40,708 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] at least one sink is marked for delete
2016-01-14 15:57:40,708 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:57:40,711 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:36271/user/teamcity/.staging/43908F910C974C6495B956DB6ACE4876/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:57:40,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] starting
2016-01-14 15:57:40,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/first1"]
2016-01-14 15:57:40,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/second1"]
2016-01-14 15:57:40,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] parallel execution of steps is enabled: true
2016-01-14 15:57:40,735 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] executing total steps: 1
2016-01-14 15:57:40,735 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] allocating management threads: 1
2016-01-14 15:57:40,736 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] starting step: (1/1) ...tform/testCascade/second1
2016-01-14 15:57:40,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] tez session mode enabled: false
2016-01-14 15:57:40,755 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 15:57:40,769 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:57:40,769 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0013
2016-01-14 15:57:40,770 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:57:40,779 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/43908F910C974C6495B956DB6ACE4876/FBC32FA501DB4C76BA026111ED902F13/.tez/application_1452786923212_0013 doesn't exist and is created
2016-01-14 15:57:40,841 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0013, dagName=[43908F910C974C6495B956DB6ACE4876/FBC32FA501DB4C76BA026111ED902F13] second1/(1/1) ...tform/testCascade/second1
2016-01-14 15:57:41,044 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0013/
2016-01-14 15:57:41,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] submitted tez dag to app master: application_1452786923212_0013, with dag id: dag_1452786923212_0013_1
2016-01-14 15:57:45,753 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0011_01_000002 is : 143
2016-01-14 15:57:46,729 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0011_01_000002
2016-01-14 15:57:55,795 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] completed in: 00:21.111, using cpu time: 00:03.230
2016-01-14 15:57:55,795 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second2
2016-01-14 15:58:00,833 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0012_01_000002 is : 143
2016-01-14 15:58:02,368 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] completed in: 00:21.634, using cpu time: 00:02.960
2016-01-14 15:58:02,368 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second1
2016-01-14 15:58:02,369 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: lhs*rhs
2016-01-14 15:58:02,369 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] at least one sink is marked for delete
2016-01-14 15:58:02,369 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 15:58:02,372 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:36271/user/teamcity/.staging/86A162F490EB4F768841A6886CE8F0FD/cascading-hadoop2-tez-3.0.4.jar
2016-01-14 15:58:02,401 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting
2016-01-14 15:58:02,401 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/second2"]
2016-01-14 15:58:02,401 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ca57560bc31094a7/apache-2.4.x-tez-0.6.x/build/test/output/hadoop2-tez/parallelcascadeplatform/testCascade/second1"]
2016-01-14 15:58:02,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] 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/parallelcascadeplatform/testCascade/third"]
2016-01-14 15:58:02,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] parallel execution of steps is enabled: true
2016-01-14 15:58:02,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executing total steps: 1
2016-01-14 15:58:02,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] allocating management threads: 1
2016-01-14 15:58:02,403 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting step: (1/1) ...latform/testCascade/third
2016-01-14 15:58:02,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] tez session mode enabled: false
2016-01-14 15:58:02,420 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 15:58:02,432 INFO client.TezClient (TezClient.java:start(315)) - Using org.apache.tez.dag.history.ats.acls.ATSHistoryACLPolicyManager to manage Timeline ACLs
2016-01-14 15:58:02,433 INFO client.TezClient (TezClient.java:submitDAGApplication(738)) - Submitting DAG application with id: application_1452786923212_0014
2016-01-14 15:58:02,433 INFO client.TezClientUtils (TezClientUtils.java:setupTezJarsLocalResources(171)) - Using tez.lib.uris value from configuration: hdfs://localhost:36271/user/teamcity/target/cascading.platform.tez.Hadoop2TezPlatform-tmpDir/TezAppJar.jar
2016-01-14 15:58:02,441 INFO client.TezClient (TezCommonUtils.java:createTezSystemStagingPath(118)) - Tez system stage directory hdfs://localhost:36271/user/teamcity/.staging/86A162F490EB4F768841A6886CE8F0FD/E32705A636F04EDDA0130B434D094E8F/.tez/application_1452786923212_0014 doesn't exist and is created
2016-01-14 15:58:02,501 INFO client.TezClient (TezClient.java:submitDAGApplication(759)) - Submitting DAG to YARN, applicationId=application_1452786923212_0014, dagName=[86A162F490EB4F768841A6886CE8F0FD/E32705A636F04EDDA0130B434D094E8F] lhs*rhs/(1/1) ...latform/testCascade/third
2016-01-14 15:58:02,504 INFO client.TezClient (TezClient.java:submitDAGApplication(765)) - The url to track the Tez AM: http://ip-10-187-41-40:55582/proxy/application_1452786923212_0014/
2016-01-14 15:58:02,517 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] submitted tez dag to app master: application_1452786923212_0014, with dag id: dag_1452786923212_0014_1
2016-01-14 15:58:07,402 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452786923212_0013_01_000002 is : 143
2016-01-14 15:58:08,387 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0013_01_000002
2016-01-14 15:58:12,274 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0014_01_000004
2016-01-14 15:58:13,274 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452786923212_0014_01_000005
2016-01-14 15:58:18,157 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] completed in: 00:15.755, using cpu time: 00:06.990
2016-01-14 15:58:18,157 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: lhs*rhs
2016-01-14 15:58:18,216 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/parallelcascadeplatform/testCascade/second2
2016-01-14 15:58:18,221 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/parallelcascadeplatform/testCascade/third
2016-01-14 15:58:18,227 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/parallelcascadeplatform/testCascade/second1
2016-01-14 15:58:18,231 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/parallelcascadeplatform/testCascade/first2
2016-01-14 15:58:18,236 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/parallelcascadeplatform/testCascade/first1