[ 
https://issues.apache.org/jira/browse/CALCITE-2018?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16351557#comment-16351557
 ] 

Volodymyr Vysotskyi commented on CALCITE-2018:
----------------------------------------------

I have added a check for stored {{RelSubset.bestCost}} into 
{{VolcanoPlanner.validate()}} method (line 907):
{code:java}
          if (subset.best != null) {
            RelOptCost bestCost = getCost(subset.best, 
RelMetadataQuery.instance());
            if (!subset.bestCost.equals(bestCost)) {
              throw new AssertionError(
                "relSubset [" + subset.getDescription()
                  + "] has wrong best cost "
                  + subset.bestCost + ". Correct cost is " + bestCost);
            }
          }
{code}
and Calcite unit tests failed:
{noformat}
Failed tests: 
  
MaterializationTest.testJoinMaterializationUKFK9:1823->checkMaterialize:198->checkMaterialize:205->checkThatMaterialize:233
 relSubset [rel#226287:Subset#8.ENUMERABLE.[]] has wrong best cost {221.5 rows, 
128.25 cpu, 0.0 io}. Correct cost is {233.0 rows, 178.0 cpu, 0.0 io}
  ScannableTableTest.testPFPushDownProjectFilterAggregateNested:279 relSubset 
[rel#12950:Subset#5.ENUMERABLE.[]] has wrong best cost {63.8 rows, 62.308 cpu, 
0.0 io}. Correct cost is {70.4 rows, 60.404 cpu, 0.0 io}
  ScannableTableTest.testPFTableRefusesFilterCooperative:221 relSubset 
[rel#13382:Subset#2.ENUMERABLE.[]] has wrong best cost {81.0 rows, 181.01 cpu, 
0.0 io}. Correct cost is {150.5 rows, 250.505 cpu, 0.0 io}
  ScannableTableTest.testProjectableFilterableCooperative:148 relSubset 
[rel#13611:Subset#2.ENUMERABLE.[]] has wrong best cost {81.0 rows, 181.01 cpu, 
0.0 io}. Correct cost is {150.5 rows, 250.505 cpu, 0.0 io}
  ScannableTableTest.testProjectableFilterableNonCooperative:165 relSubset 
[rel#13754:Subset#2.ENUMERABLE.[]] has wrong best cost {81.0 rows, 181.01 cpu, 
0.0 io}. Correct cost is {150.5 rows, 250.505 cpu, 0.0 io}
  FrameworksTest.testUpdate:336->executeQuery:367 relSubset 
[rel#22533:Subset#2.ENUMERABLE.any] has wrong best cost {19.5 rows, 37.75 cpu, 
0.0 io}. Correct cost is {22.575 rows, 52.58 cpu, 0.0 io}
{noformat}
The root cause is the same as for the test failure in the comment above - the 
cumulative cost of best rel node increased.

To ensure that this failure was not caused by incorrect metadata caching, I 
made changes in {{RelOptCluster.getMetadataQuery()}} method so it always 
returns {{RelMetadataQuery.instance()}}, therefore cached metadata isn't used.

[~julianhyde], since this issue does not connect with metadata caching, may we 
merge existing pull request without those additional checks, and create a 
separate Jira to fix the issue described in these two last comments?

Regarding this fix, we have used it in Calcite fork which is used by Drill and 
it allowed executing of several queries that failed with 
{{CannotPlanException}} before. Also, all unit and functional Drill tests are 
passed with enabled check {{VolcanoPlanner.validate()}} (without adding these 
additional checks that we mentioned).

> 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
>            Priority: Critical
>             Fix For: 1.16.0
>
>
> *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
(v7.6.3#76005)

Reply via email to