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 <zabe...@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.")); } }