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

Queries failed with AssertionError: rel has lower cost than best cost of subset

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 1.13.0
    • Fix Version/s: 1.22.0
    • Component/s: core

      Description

      Problem description
      When rootLogger level is DEBUG, unit tests

      • MaterializationTest.testMaterializationSubstitution2
      • MaterializationTest.testJoinMaterializationUKFK8
      • MaterializationTest.testJoinMaterializationUKFK6
      • JdbcTest.testWhereNot

      unit tests are failed with error AssertionError: rel has lower cost than best cost of subset.

      Full stack trace for test MaterializationTest.testMaterializationSubstitution2:

      java.lang.AssertionError: rel [rel#245:EnumerableUnion.ENUMERABLE.[](input#0=rel#246:Subset#5.ENUMERABLE.[],input#1=rel#239:Subset#6.ENUMERABLE.[0],all=true)] has lower cost {14.0 rows, 19.0 cpu, 0.0 io} than best cost {15.0 rows, 20.0 cpu, 0.0 io} of subset [rel#243:Subset#7.ENUMERABLE.[]]
      
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.validate(VolcanoPlanner.java:906)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.register(VolcanoPlanner.java:866)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:883)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:101)
      	at org.apache.calcite.rel.AbstractRelNode.onRegister(AbstractRelNode.java:336)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.registerImpl(VolcanoPlanner.java:1495)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.register(VolcanoPlanner.java:863)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:883)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:1766)
      	at org.apache.calcite.plan.volcano.VolcanoRuleCall.transformTo(VolcanoRuleCall.java:135)
      	at org.apache.calcite.plan.RelOptRuleCall.transformTo(RelOptRuleCall.java:234)
      	at org.apache.calcite.rel.rules.FilterProjectTransposeRule.onMatch(FilterProjectTransposeRule.java:143)
      	at org.apache.calcite.plan.volcano.VolcanoRuleCall.onMatch(VolcanoRuleCall.java:212)
      	at org.apache.calcite.plan.volcano.VolcanoPlanner.findBestExp(VolcanoPlanner.java:650)
      	at org.apache.calcite.tools.Programs$5.run(Programs.java:326)
      	at org.apache.calcite.tools.Programs$SequenceProgram.run(Programs.java:387)
      	at org.apache.calcite.prepare.Prepare.optimize(Prepare.java:187)
      	at org.apache.calcite.prepare.Prepare.prepareSql(Prepare.java:318)
      	at org.apache.calcite.prepare.Prepare.prepareSql(Prepare.java:229)
      	at org.apache.calcite.prepare.CalcitePrepareImpl.prepare2_(CalcitePrepareImpl.java:786)
      	at org.apache.calcite.prepare.CalcitePrepareImpl.prepare_(CalcitePrepareImpl.java:640)
      	at org.apache.calcite.prepare.CalcitePrepareImpl.prepareSql(CalcitePrepareImpl.java:610)
      	at org.apache.calcite.schema.Schemas.prepare(Schemas.java:346)
      	at org.apache.calcite.materialize.MaterializationService$DefaultTableFactory.createTable(MaterializationService.java:374)
      	at org.apache.calcite.materialize.MaterializationService.defineMaterialization(MaterializationService.java:137)
      	at org.apache.calcite.materialize.MaterializationService.defineMaterialization(MaterializationService.java:99)
      	at org.apache.calcite.schema.impl.MaterializedViewTable$MaterializedViewTableMacro.<init>(MaterializedViewTable.java:110)
      	at org.apache.calcite.schema.impl.MaterializedViewTable$MaterializedViewTableMacro.<init>(MaterializedViewTable.java:100)
      	at org.apache.calcite.schema.impl.MaterializedViewTable.create(MaterializedViewTable.java:81)
      	at org.apache.calcite.model.ModelHandler.visit(ModelHandler.java:364)
      	at org.apache.calcite.model.JsonMaterialization.accept(JsonMaterialization.java:42)
      	at org.apache.calcite.model.JsonSchema.visitChildren(JsonSchema.java:98)
      	at org.apache.calcite.model.JsonMapSchema.visitChildren(JsonMapSchema.java:48)
      	at org.apache.calcite.model.ModelHandler.populateSchema(ModelHandler.java:257)
      	at org.apache.calcite.model.ModelHandler.visit(ModelHandler.java:273)
      	at org.apache.calcite.model.JsonCustomSchema.accept(JsonCustomSchema.java:45)
      	at org.apache.calcite.model.ModelHandler.visit(ModelHandler.java:196)
      	at org.apache.calcite.model.ModelHandler.<init>(ModelHandler.java:88)
      	at org.apache.calcite.jdbc.Driver$1.onConnectionInit(Driver.java:104)
      	at org.apache.calcite.avatica.UnregisteredDriver.connect(UnregisteredDriver.java:139)
      	at java.sql.DriverManager.getConnection(DriverManager.java:571)
      	at java.sql.DriverManager.getConnection(DriverManager.java:187)
      	at org.apache.calcite.test.CalciteAssert$MapConnectionFactory.createConnection(CalciteAssert.java:1227)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.createConnection(CalciteAssert.java:1266)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.returns(CalciteAssert.java:1337)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.returns(CalciteAssert.java:1320)
      	at org.apache.calcite.test.CalciteAssert$AssertQuery.sameResultWithMaterializationsDisabled(CalciteAssert.java:1548)
      	at org.apache.calcite.test.MaterializationTest.testMaterializationSubstitution2(MaterializationTest.java:2062)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:606)
      	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)
      

      Possible root cause
      JaninoRelMetadataProvider caches metadata queries of RelSubset even when RelSubset.best value is not set.
      Actually not all RelNodes in RelSubset.set.rels have the same row count for some queries.
      When RelMetadataQuery.getRowCount(RelNode rel) method is called with RelSubset instance without best value, row count of RelSubset.set.rel is cached.
      After assigning best relNode, the RelMetadataQuery.getRowCount(RelNode rel) method returns old cached value if RelMetadataQuery instance still the same.
      This error appears when row count for best relNode is different from set.rel relNode.

      In the test MaterializationTest.testMaterializationSubstitution2 row count of rel#237:LogicalFilter was cached and returned its value when relSubset had best rel#347:EnumerableFilter.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                danny0405 Danny Chen
                Reporter:
                volodymyr Vova Vysotskyi
              • Votes:
                2 Vote for this issue
                Watchers:
                19 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 - 3h 40m
                  3h 40m