Xiening Dai created CALCITE-3257: ------------------------------------ Summary: Need to clear RelMetaDataQuery cache after dumping RelNodes and Graphviz Key: CALCITE-3257 URL: https://issues.apache.org/jira/browse/CALCITE-3257 Project: Calcite Issue Type: Bug Components: core Reporter: Xiening Dai
To repro - 1. Set Log4J log level to TRACE. So planner will dump rel node info every time at rule match (https://github.com/apache/calcite/blob/3124a85b93ff2f1b79484c7bd4cc41835d4f1920/core/src/main/java/org/apache/calcite/plan/volcano/RuleQueue.java#L435) 2. Run JdbcTest.testInnerJoinValues. Get below exception - java.lang.AssertionError: rel [rel#2128:EnumerableProject.ENUMERABLE.[](input=RelSubset#2122,EMPNO=$0,DESC=$3)] has lower cost {309.75 rows, 215.5 cpu, 0.0 io} than best cost {322.5 rows, 241.0 cpu, 0.0 io} of subset [rel#2119:Subset#5.ENUMERABLE.[]] at org.apache.calcite.util.Litmus$1.fail(Litmus.java:31) at org.apache.calcite.plan.volcano.VolcanoPlanner.isValid(VolcanoPlanner.java:888) at org.apache.calcite.plan.volcano.VolcanoPlanner.register(VolcanoPlanner.java:851) at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:868) at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:90) at org.apache.calcite.rel.AbstractRelNode.onRegister(AbstractRelNode.java:329) at org.apache.calcite.plan.volcano.VolcanoPlanner.registerImpl(VolcanoPlanner.java:1656) at org.apache.calcite.plan.volcano.VolcanoPlanner.register(VolcanoPlanner.java:846) at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:868) at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:1927) at org.apache.calcite.plan.volcano.VolcanoRuleCall.transformTo(VolcanoRuleCall.java:129) at org.apache.calcite.plan.RelOptRuleCall.transformTo(RelOptRuleCall.java:236) at org.apache.calcite.rel.rules.AggregateProjectMergeRule.onMatch(AggregateProjectMergeRule.java:74) at org.apache.calcite.plan.volcano.VolcanoRuleCall.onMatch(VolcanoRuleCall.java:208) at org.apache.calcite.plan.volcano.VolcanoPlanner.findBestExp(VolcanoPlanner.java:631) at org.apache.calcite.tools.Programs.lambda$standard$3(Programs.java:286) at org.apache.calcite.tools.Programs$SequenceProgram.run(Programs.java:346) at org.apache.calcite.prepare.Prepare.optimize(Prepare.java:189) at org.apache.calcite.prepare.Prepare.prepareSql(Prepare.java:314) at org.apache.calcite.prepare.Prepare.prepareSql(Prepare.java:231) at org.apache.calcite.prepare.CalcitePrepareImpl.prepare2_(CalcitePrepareImpl.java:638) at org.apache.calcite.prepare.CalcitePrepareImpl.prepare_(CalcitePrepareImpl.java:502) at org.apache.calcite.prepare.CalcitePrepareImpl.prepareSql(CalcitePrepareImpl.java:472) at org.apache.calcite.jdbc.CalciteConnectionImpl.parseQuery(CalciteConnectionImpl.java:231) 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) at org.apache.calcite.avatica.AvaticaStatement.executeQuery(AvaticaStatement.java:227) at org.apache.calcite.test.CalciteAssert.assertQuery(CalciteAssert.java:522) at org.apache.calcite.test.CalciteAssert$AssertQuery.lambda$returns$1(CalciteAssert.java:1466) at org.apache.calcite.test.CalciteAssert$AssertQuery.withConnection(CalciteAssert.java:1398) at org.apache.calcite.test.CalciteAssert$AssertQuery.returns(CalciteAssert.java:1464) at org.apache.calcite.test.CalciteAssert$AssertQuery.explainMatches(CalciteAssert.java:1561) at org.apache.calcite.test.CalciteAssert$AssertQuery.explainContains(CalciteAssert.java:1556) at org.apache.calcite.test.JdbcTest.testInnerJoinValues(JdbcTest.java:2580) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) 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.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.junit.runner.JUnitCore.run(JUnitCore.java:137) at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68) at com.intellij.rt.execution.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:47) at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:242) at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:70) Suppressed: org.apache.calcite.util.TestUtil$ExtraInformation: With materializationsEnabled=false, limit=0, sql=explain plan for select empno, desc from sales.emps, (SELECT * FROM (VALUES (10, 'SameName')) AS t (id, desc)) as sn where emps.deptno = sn.id and sn.desc = 'SameName' group by empno, desc at org.apache.calcite.util.TestUtil.rethrow(TestUtil.java:268) at org.apache.calcite.test.CalciteAssert.assertQuery(CalciteAssert.java:554) ... 28 more Based on current design, RelMetadataQuery.map needs to be cleared between each rule firing. This is achieve through RelOptCluster.invalidateMetadataQuery() by VolcanoRuleCall.transformTo(). But when trace is enabled, the dump process would actually rebuild the meta data cache from previous rel tree. Then the subsequent rule firing doesn't get a chance to update rel node cost as it's been in the cache. A simple fix will just add a call to RelOptCluster.invalidateMetadataQuery() after dumping rel nodes. -- This message was sent by Atlassian JIRA (v7.6.14#76016)