You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@calcite.apache.org by za...@apache.org on 2019/11/27 06:34:27 UTC

[calcite] 01/02: [CALCITE-3140] Multiple failures when executing slow tests

This is an automated email from the ASF dual-hosted git repository.

zabetak pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/calcite.git

commit 6ad3f9a97b2c68ad9b08e9f6099ce9c5e1fd9a80
Author: Stamatis Zampetakis <za...@gmail.com>
AuthorDate: Fri Jul 19 16:00:06 2019 +0200

    [CALCITE-3140] Multiple failures when executing slow tests
    
    1. Handle errors in SqlOperatorBaseTest#testArgumentBounds skipping problematic calls with appropriate explanation.
    2. Introduce Bug#CALCITE_3243 related with failures in SqlOperatorBaseTest#testArgumentBounds.
    3. Errors and exceptions in SqlOperatorBaseTest#testArgumentBounds are not that different so log everything instead of rethrowing errors.
    4. Improve the error messages in SqlOperatorBaseTest#testArgumentBounds by trying to find the most descriptive cause for the failure.
    5. Use logger instead of System.out in SqlOperatorBaseTest#testArgumentBounds for printing messages.
    6. Skip queries 2 and 7 of TpchTest due to CALCITE-2223 and infinite planning bug.
    7. Increase the timeout by 2 in FoodmartTest to avoid (marginal) failures (i.e., queries 2420, 5894) in slower machines.
    8. Update stale plan in TpcdsTest#testQuery17Plan.
---
 .../src/main/java/org/apache/calcite/util/Bug.java | 13 +++++
 .../apache/calcite/util/trace/CalciteTrace.java    |  8 +++
 .../calcite/sql/test/SqlOperatorBaseTest.java      | 66 +++++++++++++++++++---
 .../java/org/apache/calcite/test/FoodmartTest.java |  2 +-
 .../apache/calcite/adapter/tpcds/TpcdsTest.java    |  2 +-
 .../org/apache/calcite/adapter/tpch/TpchTest.java  | 30 ++++------
 6 files changed, 92 insertions(+), 29 deletions(-)

diff --git a/core/src/main/java/org/apache/calcite/util/Bug.java b/core/src/main/java/org/apache/calcite/util/Bug.java
index 689ec99..c9735f8 100644
--- a/core/src/main/java/org/apache/calcite/util/Bug.java
+++ b/core/src/main/java/org/apache/calcite/util/Bug.java
@@ -152,6 +152,14 @@ public abstract class Bug {
    * Decorrelate sub-queries in Project and Join</a> is fixed. */
   public static final boolean CALCITE_1045_FIXED = false;
 
+  /**
+   * Whether
+   * <a href="https://issues.apache.org/jira/browse/CALCITE-2223">[CALCITE-2223]
+   * ProjectMergeRule is infinitely matched when is applied after ProjectReduceExpressions Rule</a>
+   * is fixed.
+   */
+  public static final boolean CALCITE_2223_FIXED = false;
+
   /** Whether
    * <a href="https://issues.apache.org/jira/browse/CALCITE-2400">[CALCITE-2400]
    * Allow standards-compliant column ordering for NATURAL JOIN and JOIN USING
@@ -174,6 +182,11 @@ public abstract class Bug {
    * JSON data type support</a> is fixed. */
   public static final boolean CALCITE_2869_FIXED = false;
 
+  /** Whether
+   * <a href="https://issues.apache.org/jira/browse/CALCITE-3243">[CALCITE-3243]
+   * Incomplete validation of operands in JSON functions</a> is fixed. */
+  public static final boolean CALCITE_3243_FIXED = false;
+
   /**
    * Use this to flag temporary code.
    */
diff --git a/core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java b/core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
index 25b5a77..aa25692 100644
--- a/core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
+++ b/core/src/main/java/org/apache/calcite/util/trace/CalciteTrace.java
@@ -119,6 +119,14 @@ public abstract class CalciteTrace {
   }
 
   /**
+   * The tracers report important/useful information related with the execution
+   * of unit tests.
+   */
+  public static Logger getTestTracer(Class<?> testClass) {
+    return LoggerFactory.getLogger(testClass.getName());
+  }
+
+  /**
    * Thread-local handler that is called with dynamically generated Java code.
    * It exists for unit-testing.
    * The handler is never null; the default handler does nothing.
diff --git a/core/src/test/java/org/apache/calcite/sql/test/SqlOperatorBaseTest.java b/core/src/test/java/org/apache/calcite/sql/test/SqlOperatorBaseTest.java
index 1b1ce0d..ef28246 100644
--- a/core/src/test/java/org/apache/calcite/sql/test/SqlOperatorBaseTest.java
+++ b/core/src/test/java/org/apache/calcite/sql/test/SqlOperatorBaseTest.java
@@ -23,6 +23,8 @@ import org.apache.calcite.linq4j.Linq4j;
 import org.apache.calcite.plan.Strong;
 import org.apache.calcite.rel.type.RelDataType;
 import org.apache.calcite.rel.type.RelDataTypeFactory;
+import org.apache.calcite.runtime.CalciteContextException;
+import org.apache.calcite.runtime.CalciteException;
 import org.apache.calcite.runtime.Hook;
 import org.apache.calcite.sql.SqlAggFunction;
 import org.apache.calcite.sql.SqlCall;
@@ -40,6 +42,7 @@ import org.apache.calcite.sql.fun.SqlLibrary;
 import org.apache.calcite.sql.fun.SqlLibraryOperatorTableFactory;
 import org.apache.calcite.sql.fun.SqlLibraryOperators;
 import org.apache.calcite.sql.fun.SqlStdOperatorTable;
+import org.apache.calcite.sql.parser.SqlParseException;
 import org.apache.calcite.sql.parser.SqlParserPos;
 import org.apache.calcite.sql.pretty.SqlPrettyWriter;
 import org.apache.calcite.sql.type.BasicSqlType;
@@ -60,12 +63,14 @@ import org.apache.calcite.util.Pair;
 import org.apache.calcite.util.TestUtil;
 import org.apache.calcite.util.TimestampString;
 import org.apache.calcite.util.Util;
+import org.apache.calcite.util.trace.CalciteTrace;
 
 import com.google.common.base.Throwables;
 
 import org.junit.Before;
 import org.junit.Ignore;
 import org.junit.Test;
+import org.slf4j.Logger;
 
 import java.math.BigDecimal;
 import java.sql.Connection;
@@ -77,8 +82,10 @@ import java.util.ArrayList;
 import java.util.Arrays;
 import java.util.Calendar;
 import java.util.Collections;
+import java.util.HashSet;
 import java.util.List;
 import java.util.Locale;
+import java.util.Set;
 import java.util.TimeZone;
 import java.util.function.Consumer;
 import java.util.function.UnaryOperator;
@@ -148,6 +155,8 @@ import static org.junit.Assume.assumeTrue;
 public abstract class SqlOperatorBaseTest {
   //~ Static fields/initializers ---------------------------------------------
 
+  private static final Logger LOGGER = CalciteTrace.getTestTracer(SqlOperatorBaseTest.class);
+
   // TODO: Change message when Fnl3Fixed to something like
   // "Invalid character for cast: PC=0 Code=22018"
   public static final String INVALID_CHAR_MESSAGE =
@@ -8791,7 +8800,16 @@ public abstract class SqlOperatorBaseTest {
   }
 
   /** Test that calls all operators with all possible argument types, and for
-   * each type, with a set of tricky values. */
+   * each type, with a set of tricky values.
+   *
+   * This is not really a unit test since there are no assertions;
+   * it either succeeds or fails in the preparation of the operator case
+   * and not when actually testing (validating/executing) the call.
+   *
+   * Nevertheless the log messages conceal many problems which potentially need
+   * to be fixed especially cases where the query passes from the validation stage
+   * and fails at runtime.
+   * */
   @Test public void testArgumentBounds() {
     if (!CalciteSystemProperty.TEST_SLOW.value()) {
       return;
@@ -8811,10 +8829,26 @@ public abstract class SqlOperatorBaseTest {
     builder.add1(SqlTypeName.VARCHAR, 11, "", " ", "hello world");
     builder.add1(SqlTypeName.CHAR, 5, "", "e", "hello");
     builder.add0(SqlTypeName.TIMESTAMP, 0L, DateTimeUtils.MILLIS_PER_DAY);
+
+    Set<SqlOperator> operatorsToSkip = new HashSet<>();
+    if (!Bug.CALCITE_3243_FIXED) {
+      // TODO: Remove entirely the if block when the bug is fixed
+      // REVIEW zabetak 12-August-2019: It may still make sense to avoid the
+      // JSON functions since for most of the values above they are expected
+      // to raise an error and due to the big number of operands they accept
+      // they increase significantly the running time of the method.
+      operatorsToSkip.add(SqlStdOperatorTable.JSON_VALUE);
+      operatorsToSkip.add(SqlStdOperatorTable.JSON_VALUE_ANY);
+      operatorsToSkip.add(SqlStdOperatorTable.JSON_QUERY);
+    }
+    // Skip since ClassCastException is raised in SqlOperator#unparse
+    // since the operands of the call do not have the expected type.
+    // Moreover, the values above do not make much sense for this operator.
+    operatorsToSkip.add(SqlStdOperatorTable.WITHIN_GROUP);
+    operatorsToSkip.add(SqlStdOperatorTable.TRIM); // can't handle the flag argument
+    operatorsToSkip.add(SqlStdOperatorTable.EXISTS);
     for (SqlOperator op : SqlStdOperatorTable.instance().getOperatorList()) {
-      switch (op.getKind()) {
-      case TRIM: // can't handle the flag argument
-      case EXISTS:
+      if (operatorsToSkip.contains(op)) {
         continue;
       }
       switch (op.getSyntax()) {
@@ -8873,17 +8907,31 @@ public abstract class SqlOperatorBaseTest {
               tester.check(query, SqlTests.ANY_TYPE_CHECKER,
                   SqlTests.ANY_PARAMETER_CHECKER, result -> { });
             }
-          } catch (Error e) {
-            System.out.println(s + ": " + e.getMessage());
-            throw e;
-          } catch (Exception e) {
-            System.out.println("Failed: " + s + ": " + e.getMessage());
+          } catch (Throwable e) {
+            // Logging the top-level throwable directly makes the message
+            // difficult to read since it either contains too much information
+            // or very few details.
+            Throwable cause = findMostDescriptiveCause(e);
+            LOGGER.info("Failed: " + s + ": " + cause);
           }
         }
       }
     }
   }
 
+  private Throwable findMostDescriptiveCause(Throwable ex) {
+    if (ex instanceof CalciteException
+        || ex instanceof CalciteContextException
+        || ex instanceof SqlParseException) {
+      return ex;
+    }
+    Throwable cause = ex.getCause();
+    if (cause != null) {
+      return findMostDescriptiveCause(cause);
+    }
+    return ex;
+  }
+
   private List<Object> getValues(BasicSqlType type, boolean inBound) {
     List<Object> values = new ArrayList<Object>();
     for (boolean sign : FALSE_TRUE) {
diff --git a/core/src/test/java/org/apache/calcite/test/FoodmartTest.java b/core/src/test/java/org/apache/calcite/test/FoodmartTest.java
index a905f9b..d9165f3 100644
--- a/core/src/test/java/org/apache/calcite/test/FoodmartTest.java
+++ b/core/src/test/java/org/apache/calcite/test/FoodmartTest.java
@@ -151,7 +151,7 @@ public class FoodmartTest {
     assert query.id == id : id + ":" + query.id;
   }
 
-  @Test(timeout = 60000)
+  @Test(timeout = 120000)
   public void test() {
     try {
       CalciteAssert.that()
diff --git a/plus/src/test/java/org/apache/calcite/adapter/tpcds/TpcdsTest.java b/plus/src/test/java/org/apache/calcite/adapter/tpcds/TpcdsTest.java
index 2cce3f5..b1ecb00 100644
--- a/plus/src/test/java/org/apache/calcite/adapter/tpcds/TpcdsTest.java
+++ b/plus/src/test/java/org/apache/calcite/adapter/tpcds/TpcdsTest.java
@@ -219,7 +219,7 @@ public class TpcdsTest {
         .withHook(Hook.PROGRAM, handler(true, 2))
         .explainMatches("including all attributes ",
             CalciteAssert.checkMaskedResultContains(""
-                + "EnumerableCalc(expr#0..9=[{inputs}], expr#10=[/($t4, $t3)], expr#11=[CAST($t10):INTEGER NOT NULL], expr#12=[*($t4, $t4)], expr#13=[/($t12, $t3)], expr#14=[-($t5, $t13)], expr#15=[1], expr#16=[=($t3, $t15)], expr#17=[null], expr#18=[-($t3, $t15)], expr#19=[CASE($t16, $t17, $t18)], expr#20=[/($t14, $t19)], expr#21=[0.5], expr#22=[POWER($t20, $t21)], expr#23=[CAST($t22):INTEGER NOT NULL], expr#24=[/($t23, $t11)], expr#25=[/($t6, $t3)], expr#26=[CAST($t25):INTEGER NOT NULL [...]
+                + "EnumerableCalc(expr#0..9=[{inputs}], expr#10=[/($t4, $t3)], expr#11=[CAST($t10):INTEGER NOT NULL], expr#12=[*($t4, $t4)], expr#13=[/($t12, $t3)], expr#14=[-($t5, $t13)], expr#15=[1], expr#16=[=($t3, $t15)], expr#17=[null:BIGINT], expr#18=[-($t3, $t15)], expr#19=[CASE($t16, $t17, $t18)], expr#20=[/($t14, $t19)], expr#21=[0.5:DECIMAL(2, 1)], expr#22=[POWER($t20, $t21)], expr#23=[CAST($t22):INTEGER NOT NULL], expr#24=[/($t23, $t11)], expr#25=[/($t6, $t3)], expr#26=[CAST($ [...]
                 + "  EnumerableLimit(fetch=[100]): rowcount = 100.0, cumulative cost = {1.2435775409784036E28 rows, 2.555295485909236E30 cpu, 0.0 io}\n"
                 + "    EnumerableSort(sort0=[$0], sort1=[$1], sort2=[$2], dir0=[ASC], dir1=[ASC], dir2=[ASC]): rowcount = 5.434029018852197E26, cumulative cost = {1.2435775409784036E28 rows, 2.555295485909236E30 cpu, 0.0 io}\n"
                 + "      EnumerableAggregate(group=[{0, 1, 2}], STORE_SALES_QUANTITYCOUNT=[COUNT()], agg#1=[$SUM0($3)], agg#2=[$SUM0($6)], agg#3=[$SUM0($4)], agg#4=[$SUM0($7)], agg#5=[$SUM0($5)], agg#6=[$SUM0($8)]): rowcount = 5.434029018852197E26, cumulative cost = {1.1892372507898816E28 rows, 1.2172225002228922E30 cpu, 0.0 io}\n"
diff --git a/plus/src/test/java/org/apache/calcite/adapter/tpch/TpchTest.java b/plus/src/test/java/org/apache/calcite/adapter/tpch/TpchTest.java
index 1199559..7bc1440 100644
--- a/plus/src/test/java/org/apache/calcite/adapter/tpch/TpchTest.java
+++ b/plus/src/test/java/org/apache/calcite/adapter/tpch/TpchTest.java
@@ -19,11 +19,12 @@ package org.apache.calcite.adapter.tpch;
 import org.apache.calcite.config.CalciteSystemProperty;
 import org.apache.calcite.plan.RelOptUtil;
 import org.apache.calcite.test.CalciteAssert;
+import org.apache.calcite.util.Bug;
 import org.apache.calcite.util.TestUtil;
-import org.apache.calcite.util.Util;
 
 import com.google.common.collect.ImmutableList;
 
+import org.junit.Assume;
 import org.junit.Ignore;
 import org.junit.Test;
 
@@ -800,15 +801,10 @@ public class TpchTest {
         .returnsCount(150000);
   }
 
-  private CalciteAssert.AssertThat with(boolean enable) {
-    return CalciteAssert.model(TPCH_MODEL)
-        .enable(enable);
-  }
-
   private CalciteAssert.AssertThat with() {
     // Only run on JDK 1.7 or higher. The io.airlift.tpch library requires it.
     // Only run if slow tests are enabled; the library uses lots of memory.
-    return with(ENABLE);
+    return CalciteAssert.model(TPCH_MODEL).enable(ENABLE);
   }
 
   /** Tests the customer table with scale factor 5. */
@@ -822,14 +818,14 @@ public class TpchTest {
     checkQuery(1);
   }
 
-  @Ignore("slow")
+  @Ignore("Infinite planning")
   @Test public void testQuery02() {
     checkQuery(2);
   }
 
+  @Ignore("Infinite planning")
   @Test public void testQuery02Conversion() {
-    query(2, true)
-        .enable(ENABLE)
+    query(2)
         .convertMatches(relNode -> {
           String s = RelOptUtil.toString(relNode);
           assertThat(s, not(containsString("Correlator")));
@@ -857,6 +853,7 @@ public class TpchTest {
 
   @Ignore("slow")
   @Test public void testQuery07() {
+    Assume.assumeTrue(Bug.CALCITE_2223_FIXED);
     checkQuery(7);
   }
 
@@ -931,19 +928,16 @@ public class TpchTest {
   }
 
   private void checkQuery(int i) {
-    query(i, null).runs();
+    query(i).runs();
   }
 
   /** Runs with query #i.
+   *  @param i Ordinal of query, per the benchmark, 1-based
    *
-   * @param i Ordinal of query, per the benchmark, 1-based
-   * @param enable Whether to enable query execution.
-   *     If null, use the value of {@link #ENABLE}.
-   *     Pass true only for 'fast' tests that do not read any data.
    */
-  private CalciteAssert.AssertQuery query(int i, Boolean enable) {
-    return with(Util.first(enable, ENABLE))
-        .query(QUERIES.get(i - 1).replaceAll("tpch\\.", "tpch_01."));
+  private CalciteAssert.AssertQuery query(int i) {
+    return with()
+      .query(QUERIES.get(i - 1).replaceAll("tpch\\.", "tpch_01."));
   }
 }