Uploaded image for project: 'Calcite'
  1. Calcite
  2. CALCITE-2522

CalciteAssert#returns calls e.printStackTrace() for no apparent reason

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 1.17.0
    • Fix Version/s: 1.18.0
    • Component/s: core
    • Labels:
      None

      Description

      CalciteAssert.java#L1366

      The line was introduced in CALCITE-2005. Could it be just removed?

      It causes the following exception to be printed from MaterializationTest#testTableModify even though test passes:

      java.lang.RuntimeException: With materializationsEnabled=true, limit=0
      	at org.apache.calcite.test.CalciteAssert.assertQuery(CalciteAssert.java:573)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.returns(CalciteAssert.java:1362)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.explainMatches(CalciteAssert.java:1477)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.explainContains(CalciteAssert.java:1472)
      	at org.apache.calcite.test.MaterializationTest.testTableModify(MaterializationTest.java:1987)
      	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
      	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
      	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
      	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
      	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
      	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
      	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
      	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
      	at org.apache.maven.surefire.junitcore.pc.Scheduler$1.run(Scheduler.java:410)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
      	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      	at java.base/java.lang.Thread.run(Thread.java:834)
      Caused by: java.sql.SQLException: Error while executing SQL "explain plan for upsert into "dependents"select "empid" + 1 as x, "name"from "emps" where "deptno" = 10": Node [rel#73943:Subset#4.ENUMERABLE.[]] could not be implemented; planner state:
      Root: rel#73943:Subset#4.ENUMERABLE.[]
      Original rel:
      LogicalTableModify(subset=[rel#73943:Subset#4.ENUMERABLE.[]], table=[[hr, dependents]], operation=[INSERT], flattened=[false]): rowcount = 15.0, cumulative cost = {15.0 rows, 0.0 cpu, 0.0 io}, id = 73937
        LogicalProject(subset=[rel#73936:Subset#3.NONE.[]], empid=[+($0, 1)], name=[$2]): rowcount = 15.0, cumulative cost = {15.0 rows, 30.0 cpu, 0.0 io}, id = 73935
          LogicalFilter(subset=[rel#73934:Subset#2.NONE.[]], condition=[=(CAST($1):INTEGER NOT NULL, 10)]): rowcount = 15.0, cumulative cost = {15.0 rows, 100.0 cpu, 0.0 io}, id = 73933
            LogicalProject(subset=[rel#73932:Subset#1.NONE.[]], empid=[$0], deptno=[$1], name=[$2]): rowcount = 100.0, cumulative cost = {100.0 rows, 300.0 cpu, 0.0 io}, id = 73931
              EnumerableTableScan(subset=[rel#73930:Subset#0.ENUMERABLE.[]], table=[[hr, emps]]): rowcount = 100.0, cumulative cost = {100.0 rows, 101.0 cpu, 0.0 io}, id = 73902
      Sets:
      Set#0, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name, JavaType(float) salary, JavaType(class java.lang.Integer) commission)
      	rel#73930:Subset#0.ENUMERABLE.[], best=rel#73902, importance=0.5904900000000001
      		rel#73902:EnumerableTableScan.ENUMERABLE.[](table=[hr, emps]), rowcount=100.0, cumulative cost={100.0 rows, 101.0 cpu, 0.0 io}
      Set#1, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name)
      	rel#73932:Subset#1.NONE.[], best=null, importance=0.6561
      		rel#73931:LogicalProject.NONE.[](input=rel#73930:Subset#0.ENUMERABLE.[],empid=$0,deptno=$1,name=$2), rowcount=100.0, cumulative cost={inf}
      	rel#73994:Subset#1.ENUMERABLE.[], best=rel#74006, importance=0.41969273743016755
      		rel#74006:EnumerableProject.ENUMERABLE.[](input=rel#73930:Subset#0.ENUMERABLE.[],empid=$0,deptno=$1,name=$2), rowcount=100.0, cumulative cost={200.0 rows, 401.0 cpu, 0.0 io}
      Set#2, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name)
      	rel#73934:Subset#2.NONE.[], best=null, importance=0.7290000000000001
      		rel#73933:LogicalFilter.NONE.[](input=rel#73932:Subset#1.NONE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={inf}
      		rel#73982:LogicalProject.NONE.[](input=rel#73981:Subset#7.NONE.[],empid=$0,deptno=$1,name=$2), rowcount=15.0, cumulative cost={inf}
      		rel#73988:LogicalProject.NONE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={inf}
      	rel#73975:Subset#2.ENUMERABLE.[], best=rel#74018, importance=0.49499999999999994
      		rel#73993:EnumerableProject.ENUMERABLE.[](input=rel#73992:Subset#7.ENUMERABLE.[],empid=$0,deptno=$1,name=$2), rowcount=15.0, cumulative cost={130.0 rows, 246.0 cpu, 0.0 io}
      		rel#73995:EnumerableFilter.ENUMERABLE.[](input=rel#73994:Subset#1.ENUMERABLE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={215.0 rows, 501.0 cpu, 0.0 io}
      		rel#74018:EnumerableProject.ENUMERABLE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={6.0 rows, 13.0 cpu, 0.0 io}
      	rel#73989:Subset#2.NONE.[0], best=null, importance=0.36450000000000005
      		rel#73988:LogicalProject.NONE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={inf}
      	rel#74019:Subset#2.ENUMERABLE.[0], best=rel#74018, importance=0.36450000000000005
      		rel#74018:EnumerableProject.ENUMERABLE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={6.0 rows, 13.0 cpu, 0.0 io}
      Set#3, type: RecordType(INTEGER empid, JavaType(class java.lang.String) name)
      	rel#73936:Subset#3.NONE.[], best=null, importance=0.81
      		rel#73935:LogicalProject.NONE.[](input=rel#73934:Subset#2.NONE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={inf}
      		rel#73972:LogicalProject.NONE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],$f0=+($1, 1),name=$2), rowcount=3.0, cumulative cost={inf}
      		rel#73983:LogicalProject.NONE.[](input=rel#73981:Subset#7.NONE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={inf}
      		rel#73968:LogicalProject.NONE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=+($1, 1),name=$2), rowcount=3.0, cumulative cost={inf}
      		rel#74021:LogicalProject.NONE.[](input=rel#73992:Subset#7.ENUMERABLE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={inf}
      	rel#73974:Subset#3.ENUMERABLE.[], best=rel#73973, importance=0.405
      		rel#73973:EnumerableProject.ENUMERABLE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],$f0=+($1, 1),name=$2), rowcount=3.0, cumulative cost={6.0 rows, 10.0 cpu, 0.0 io}
      		rel#73976:EnumerableProject.ENUMERABLE.[](input=rel#73975:Subset#2.ENUMERABLE.[],empid=+($0, 1),name=$2), rowcount=3.0, cumulative cost={9.0 rows, 19.0 cpu, 0.0 io}
      		rel#73977:EnumerableProject.ENUMERABLE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=+($1, 1),name=$2), rowcount=3.0, cumulative cost={6.0 rows, 10.0 cpu, 0.0 io}
      		rel#74005:EnumerableProject.ENUMERABLE.[](input=rel#73992:Subset#7.ENUMERABLE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={130.0 rows, 231.0 cpu, 0.0 io}
      Set#4, type: RecordType(BIGINT ROWCOUNT)
      	rel#73938:Subset#4.NONE.[], best=null, importance=0.9
      		rel#73937:LogicalTableModify.NONE.[](input=rel#73936:Subset#3.NONE.[],table=[hr, dependents],operation=INSERT,flattened=false), rowcount=15.0, cumulative cost={inf}
      	rel#73943:Subset#4.ENUMERABLE.[], best=null, importance=1.0
      		rel#73944:AbstractConverter.ENUMERABLE.[](input=rel#73938:Subset#4.NONE.[],convention=ENUMERABLE,sort=[]), rowcount=15.0, cumulative cost={inf}
      Set#5, type: RecordType(JavaType(int) deptno, JavaType(int) empid, JavaType(class java.lang.String) name)
      	rel#73967:Subset#5.ENUMERABLE.[1], best=rel#73914, importance=0.6561
      		rel#73914:EnumerableTableScan.ENUMERABLE.[[1]](table=[hr, m0]), rowcount=3.0, cumulative cost={3.0 rows, 4.0 cpu, 0.0 io}
      Set#7, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name, JavaType(float) salary, JavaType(class java.lang.Integer) commission)
      	rel#73981:Subset#7.NONE.[], best=null, importance=0.6561
      		rel#73979:LogicalFilter.NONE.[](input=rel#73930:Subset#0.ENUMERABLE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={inf}
      	rel#73992:Subset#7.ENUMERABLE.[], best=rel#74007, importance=0.7290000000000001
      		rel#74007:EnumerableFilter.ENUMERABLE.[](input=rel#73930:Subset#0.ENUMERABLE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={115.0 rows, 201.0 cpu, 0.0 io}
      	at org.apache.calcite.avatica.Helper.createException(Helper.java:56)
      	at org.apache.calcite.avatica.Helper.createException(Helper.java:41)
      	at org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:163)
      	at org.apache.calcite.avatica.AvaticaStatement.executeQuery(AvaticaStatement.java:227)
      	at org.apache.calcite.test.CalciteAssert.assertQuery(CalciteAssert.java:541)
      	... 22 more
      Caused by: org.apache.calcite.plan.RelOptPlanner$CannotPlanException: Node [rel#73943:Subset#4.ENUMERABLE.[]] could not be implemented; planner state:
      Root: rel#73943:Subset#4.ENUMERABLE.[]
      Original rel:
      LogicalTableModify(subset=[rel#73943:Subset#4.ENUMERABLE.[]], table=[[hr, dependents]], operation=[INSERT], flattened=[false]): rowcount = 15.0, cumulative cost = {15.0 rows, 0.0 cpu, 0.0 io}, id = 73937
        LogicalProject(subset=[rel#73936:Subset#3.NONE.[]], empid=[+($0, 1)], name=[$2]): rowcount = 15.0, cumulative cost = {15.0 rows, 30.0 cpu, 0.0 io}, id = 73935
          LogicalFilter(subset=[rel#73934:Subset#2.NONE.[]], condition=[=(CAST($1):INTEGER NOT NULL, 10)]): rowcount = 15.0, cumulative cost = {15.0 rows, 100.0 cpu, 0.0 io}, id = 73933
            LogicalProject(subset=[rel#73932:Subset#1.NONE.[]], empid=[$0], deptno=[$1], name=[$2]): rowcount = 100.0, cumulative cost = {100.0 rows, 300.0 cpu, 0.0 io}, id = 73931
              EnumerableTableScan(subset=[rel#73930:Subset#0.ENUMERABLE.[]], table=[[hr, emps]]): rowcount = 100.0, cumulative cost = {100.0 rows, 101.0 cpu, 0.0 io}, id = 73902
      Sets:
      Set#0, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name, JavaType(float) salary, JavaType(class java.lang.Integer) commission)
      	rel#73930:Subset#0.ENUMERABLE.[], best=rel#73902, importance=0.5904900000000001
      		rel#73902:EnumerableTableScan.ENUMERABLE.[](table=[hr, emps]), rowcount=100.0, cumulative cost={100.0 rows, 101.0 cpu, 0.0 io}
      Set#1, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name)
      	rel#73932:Subset#1.NONE.[], best=null, importance=0.6561
      		rel#73931:LogicalProject.NONE.[](input=rel#73930:Subset#0.ENUMERABLE.[],empid=$0,deptno=$1,name=$2), rowcount=100.0, cumulative cost={inf}
      	rel#73994:Subset#1.ENUMERABLE.[], best=rel#74006, importance=0.41969273743016755
      		rel#74006:EnumerableProject.ENUMERABLE.[](input=rel#73930:Subset#0.ENUMERABLE.[],empid=$0,deptno=$1,name=$2), rowcount=100.0, cumulative cost={200.0 rows, 401.0 cpu, 0.0 io}
      Set#2, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name)
      	rel#73934:Subset#2.NONE.[], best=null, importance=0.7290000000000001
      		rel#73933:LogicalFilter.NONE.[](input=rel#73932:Subset#1.NONE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={inf}
      		rel#73982:LogicalProject.NONE.[](input=rel#73981:Subset#7.NONE.[],empid=$0,deptno=$1,name=$2), rowcount=15.0, cumulative cost={inf}
      		rel#73988:LogicalProject.NONE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={inf}
      	rel#73975:Subset#2.ENUMERABLE.[], best=rel#74018, importance=0.49499999999999994
      		rel#73993:EnumerableProject.ENUMERABLE.[](input=rel#73992:Subset#7.ENUMERABLE.[],empid=$0,deptno=$1,name=$2), rowcount=15.0, cumulative cost={130.0 rows, 246.0 cpu, 0.0 io}
      		rel#73995:EnumerableFilter.ENUMERABLE.[](input=rel#73994:Subset#1.ENUMERABLE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={215.0 rows, 501.0 cpu, 0.0 io}
      		rel#74018:EnumerableProject.ENUMERABLE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={6.0 rows, 13.0 cpu, 0.0 io}
      	rel#73989:Subset#2.NONE.[0], best=null, importance=0.36450000000000005
      		rel#73988:LogicalProject.NONE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={inf}
      	rel#74019:Subset#2.ENUMERABLE.[0], best=rel#74018, importance=0.36450000000000005
      		rel#74018:EnumerableProject.ENUMERABLE.[[0]](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=$1,deptno=$0,name=$2), rowcount=3.0, cumulative cost={6.0 rows, 13.0 cpu, 0.0 io}
      Set#3, type: RecordType(INTEGER empid, JavaType(class java.lang.String) name)
      	rel#73936:Subset#3.NONE.[], best=null, importance=0.81
      		rel#73935:LogicalProject.NONE.[](input=rel#73934:Subset#2.NONE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={inf}
      		rel#73972:LogicalProject.NONE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],$f0=+($1, 1),name=$2), rowcount=3.0, cumulative cost={inf}
      		rel#73983:LogicalProject.NONE.[](input=rel#73981:Subset#7.NONE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={inf}
      		rel#73968:LogicalProject.NONE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=+($1, 1),name=$2), rowcount=3.0, cumulative cost={inf}
      		rel#74021:LogicalProject.NONE.[](input=rel#73992:Subset#7.ENUMERABLE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={inf}
      	rel#73974:Subset#3.ENUMERABLE.[], best=rel#73973, importance=0.405
      		rel#73973:EnumerableProject.ENUMERABLE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],$f0=+($1, 1),name=$2), rowcount=3.0, cumulative cost={6.0 rows, 10.0 cpu, 0.0 io}
      		rel#73976:EnumerableProject.ENUMERABLE.[](input=rel#73975:Subset#2.ENUMERABLE.[],empid=+($0, 1),name=$2), rowcount=3.0, cumulative cost={9.0 rows, 19.0 cpu, 0.0 io}
      		rel#73977:EnumerableProject.ENUMERABLE.[](input=rel#73967:Subset#5.ENUMERABLE.[1],empid=+($1, 1),name=$2), rowcount=3.0, cumulative cost={6.0 rows, 10.0 cpu, 0.0 io}
      		rel#74005:EnumerableProject.ENUMERABLE.[](input=rel#73992:Subset#7.ENUMERABLE.[],empid=+($0, 1),name=$2), rowcount=15.0, cumulative cost={130.0 rows, 231.0 cpu, 0.0 io}
      Set#4, type: RecordType(BIGINT ROWCOUNT)
      	rel#73938:Subset#4.NONE.[], best=null, importance=0.9
      		rel#73937:LogicalTableModify.NONE.[](input=rel#73936:Subset#3.NONE.[],table=[hr, dependents],operation=INSERT,flattened=false), rowcount=15.0, cumulative cost={inf}
      	rel#73943:Subset#4.ENUMERABLE.[], best=null, importance=1.0
      		rel#73944:AbstractConverter.ENUMERABLE.[](input=rel#73938:Subset#4.NONE.[],convention=ENUMERABLE,sort=[]), rowcount=15.0, cumulative cost={inf}
      Set#5, type: RecordType(JavaType(int) deptno, JavaType(int) empid, JavaType(class java.lang.String) name)
      	rel#73967:Subset#5.ENUMERABLE.[1], best=rel#73914, importance=0.6561
      		rel#73914:EnumerableTableScan.ENUMERABLE.[[1]](table=[hr, m0]), rowcount=3.0, cumulative cost={3.0 rows, 4.0 cpu, 0.0 io}
      Set#7, type: RecordType(JavaType(int) empid, JavaType(int) deptno, JavaType(class java.lang.String) name, JavaType(float) salary, JavaType(class java.lang.Integer) commission)
      	rel#73981:Subset#7.NONE.[], best=null, importance=0.6561
      		rel#73979:LogicalFilter.NONE.[](input=rel#73930:Subset#0.ENUMERABLE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={inf}
      	rel#73992:Subset#7.ENUMERABLE.[], best=rel#74007, importance=0.7290000000000001
      		rel#74007:EnumerableFilter.ENUMERABLE.[](input=rel#73930:Subset#0.ENUMERABLE.[],condition==(CAST($1):INTEGER NOT NULL, 10)), rowcount=15.0, cumulative cost={115.0 rows, 201.0 cpu, 0.0 io}
      	at org.apache.calcite.plan.volcano.RelSubset$CheapestPlanReplacer.visit(RelSubset.java:437)
      	at org.apache.calcite.plan.volcano.RelSubset.buildCheapestPlan(RelSubset.java:296)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.findBestExp(VolcanoPlanner.java:662)
      	at org.apache.calcite.tools.Programs.lambda$standard$3(Programs.java:298)
      	at org.apache.calcite.tools.Programs$SequenceProgram.run(Programs.java:358)
      	at org.apache.calcite.prepare.Prepare.optimize(Prepare.java:188)
      	at org.apache.calcite.prepare.Prepare.prepareSql(Prepare.java:313)
      	at org.apache.calcite.prepare.Prepare.prepareSql(Prepare.java:230)
      	at org.apache.calcite.prepare.CalcitePrepareImpl.prepare2_(CalcitePrepareImpl.java:772)
      	at org.apache.calcite.prepare.CalcitePrepareImpl.prepare_(CalcitePrepareImpl.java:636)
      	at org.apache.calcite.prepare.CalcitePrepareImpl.prepareSql(CalcitePrepareImpl.java:606)
      	at org.apache.calcite.jdbc.CalciteConnectionImpl.parseQuery(CalciteConnectionImpl.java:229)
      	at org.apache.calcite.jdbc.CalciteMetaImpl.prepareAndExecute(CalciteMetaImpl.java:550)
      	at org.apache.calcite.avatica.AvaticaConnection.prepareAndExecuteInternal(AvaticaConnection.java:675)
      	at org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:156)
      	... 24 more

        Attachments

          Activity

            People

            • Assignee:
              julianhyde Julian Hyde
              Reporter:
              vladimirsitnikov Vladimir Sitnikov
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: