[
https://issues.apache.org/jira/browse/CALCITE-2018?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16216726#comment-16216726
]
Volodymyr Vysotskyi commented on CALCITE-2018:
----------------------------------------------
Let's use {{MaterializationTest.testMaterializationSubstitution2()}} test as an
example.
One of the RenNodes whose old value was gotten from the cache is
{{rel#246:Subset}}
A problem with old cached value appears for the first time (I can be wrong when
saying that it is for the first time, but in this case, it also happens) when
RelNode {{rel#246}} has best {{rel#279:EnumerableFilter}}. When RelNode with
smaller cost than bestCost (in our case it is {{rel#347:EnumerableFilter}}) is
passed into the {{RelSubset.propagateCostImprovements0()}} method, the current
cost is calculated for the first time. At this point old value is cached.
In [this
line|https://github.com/apache/calcite/blob/56d5261abb893dd92b0a2cc4893292876a2b7880/core/src/main/java/org/apache/calcite/plan/volcano/RelSubset.java#L346]
method {{propagateCostImprovements()}} is called on the parent subset
{{rel#243:Subset}}. Again in the method {{propagateCostImprovements0()}} but
called on the parent subset {{rel#243}}, is called {{planner.getCost(rel,
mq)}}, where rel is parent RelNode for our {{rel#246}}:
{{rel#245:EnumerableUnion}}. But when calculating {{planner.getCost(rel, mq)}}
cached value for {{rel#246}} is gotten and used for futher calculations.
All these things happen when the same {{RelMetadataQuery}} instance is used.
> Queries failed with AssertionError: rel has lower cost than best cost of
> subset
> -------------------------------------------------------------------------------
>
> Key: CALCITE-2018
> URL: https://issues.apache.org/jira/browse/CALCITE-2018
> Project: Calcite
> Issue Type: Bug
> Components: core
> Affects Versions: 1.13.0
> Reporter: Volodymyr Vysotskyi
> Assignee: Julian Hyde
>
> *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}}:
> {noformat}
> 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)
> {noformat}
> *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}}.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
