[CALCITE-2522] CalciteAssert#returns calls e.printStackTrace() for no apparent reason - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Closed
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:: Julian Hyde

Reporter:: Vladimir Sitnikov

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 01/Sep/18 00:45

Updated:: 23/Dec/18 00:12

Resolved:: 02/Sep/18 06:34