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

RelMetadataQuery cache is not invalidated when log trace is enabled

    XMLWordPrintableJSON

    Details

      Description

      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.testNotExistsCorrelated. Get below exception -

      java.lang.AssertionError: rel [rel#63:EnumerableAggregate.ENUMERABLE.[](input=RelSubset#62,group=

      {0}

      )] has lower cost

      {131.0 rows, 216.0 cpu, 0.0 io}

      than best cost

      {131.5 rows, 216.0 cpu, 0.0 io}

      of subset rel#60:Subset#4.ENUMERABLE.[]

      at org.apache.calcite.util.Litmus$1.fail(Litmus.java:31)
      at org.apache.calcite.plan.volcano.VolcanoPlanner.isValid(VolcanoPlanner.java:889)
      at org.apache.calcite.plan.volcano.VolcanoPlanner.register(VolcanoPlanner.java:852)
      at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:869)
      at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:1928)
      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.convert.ConverterRule.onMatch(ConverterRule.java:141)
      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.testNotExistsCorrelated(JdbcTest.java:4562)
      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 * from "hr"."emps" where not exists (
      select 1 from "hr"."depts"
      where "emps"."deptno"="depts"."deptno")
      at org.apache.calcite.util.TestUtil.rethrow(TestUtil.java:268)
      at org.apache.calcite.test.CalciteAssert.assertQuery(CalciteAssert.java:554)
      ... 28 more

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                xndai Xiening Dai
              • Votes:
                0 Vote for this issue
                Watchers:
                5 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 1h
                  1h