You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@drill.apache.org by George Spofford <ge...@gmail.com> on 2015/07/10 18:19:17 UTC
Drill calcite tracing issue
(If there's a better target for an issue request, please let me know!)
While trying to understand the details Calcite rule execution, I turned on
the Calcite tracing per
https://calcite.incubator.apache.org/docs/howto.html#tracing . At that
point (running a query from the web UI) I get the error
Query Failed: An Error Occurred
org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR:
AssertionError: Internal error: should never get here ...
The query is pretty straightforward:
select Person, sum(Qty1) from mongo.mine.test group by Person
A simple trial with the same settings against the Apache Calcite
example/csv doesn't show the same behavior. (Calcite query: SELECT DEPTNO,
SUM(EMPNO) FROM emps GROUP BY DEPTNO ; )
In Drill, I'm querying against a Mongo db but the code path in the
exception trace doesn't immediately appear to be relevant for that. It
seems to happen the very first time dumpGraph is called.
The innermost cause (in all its glory) is due to the method:
@Override public RelOptCost computeSelfCost(RelOptPlanner planner) {
// HepRelMetadataProvider is supposed to intercept this
// and redirect to the real rels.
throw Util.newInternal("should never get here");
}
and the trace is:
cause {
exception_class: "java.lang.AssertionError"
message: "Internal error: should never get here"
stack_trace {
class_name: "org.apache.calcite.util.Util"
file_name: "Util.java"
line_number: 775
method_name: "newInternal"
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.plan.hep.HepRelVertex"
file_name: "HepRelVertex.java"
line_number: 68
method_name: "computeSelfCost"
is_native_method: false
}
stack_trace {
class_name:
"org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
file_name: "RelMdPercentageOriginalRows.java"
line_number: 165
method_name: "getNonCumulativeCost"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
stack_trace {
class_name:
"org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
file_name: "ReflectiveRelMetadataProvider.java"
line_number: 194
method_name: "invoke"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.rel.metadata.RelMetadataQuery"
file_name: "RelMetadataQuery.java"
line_number: 115
method_name: "getNonCumulativeCost"
is_native_method: false
}
stack_trace {
class_name:
"org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
file_name: "RelMdPercentageOriginalRows.java"
line_number: 151
method_name: "getCumulativeCost"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
stack_trace {
class_name:
"org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
file_name: "ReflectiveRelMetadataProvider.java"
line_number: 194
method_name: "invoke"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.rel.metadata.RelMetadataQuery"
file_name: "RelMetadataQuery.java"
line_number: 101
method_name: "getCumulativeCost"
is_native_method: false
}
stack_trace {
class_name:
"org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
file_name: "RelMdPercentageOriginalRows.java"
line_number: 154
method_name: "getCumulativeCost"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
stack_trace {
class_name:
"org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
file_name: "ReflectiveRelMetadataProvider.java"
line_number: 194
method_name: "invoke"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.rel.metadata.RelMetadataQuery"
file_name: "RelMetadataQuery.java"
line_number: 101
method_name: "getCumulativeCost"
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.plan.AbstractRelOptPlanner"
file_name: "AbstractRelOptPlanner.java"
line_number: 251
method_name: "getCost"
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.plan.hep.HepPlanner"
file_name: "HepPlanner.java"
line_number: 962
method_name: "dumpGraph"
is_native_method: false
}
stack_trace {
class_name: "org.apache.calcite.plan.hep.HepPlanner"
file_name: "HepPlanner.java"
line_number: 151
method_name: "setRoot"
is_native_method: false
}
stack_trace {
class_name:
"org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
file_name: "DefaultSqlHandler.java"
line_number: 449
method_name: "convertToRel"
is_native_method: false
}
stack_trace {
class_name:
"org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
file_name: "DefaultSqlHandler.java"
line_number: 191
method_name: "validateAndConvert"
is_native_method: false
}
stack_trace {
class_name:
"org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
file_name: "DefaultSqlHandler.java"
line_number: 157
method_name: "getPlan"
is_native_method: false
}
stack_trace {
class_name: "org.apache.drill.exec.planner.sql.DrillSqlWorker"
file_name: "DrillSqlWorker.java"
line_number: 178
method_name: "getPlan"
is_native_method: false
}
stack_trace {
class_name: "org.apache.drill.exec.work.foreman.Foreman"
file_name: "Foreman.java"
line_number: 903
method_name: "runSQL"
is_native_method: false
}
stack_trace {
class_name: "org.apache.drill.exec.work.foreman.Foreman"
file_name: "Foreman.java"
line_number: 242
method_name: "run"
is_native_method: false
}
stack_trace {
class_name: "..."
line_number: 0
method_name: "..."
is_native_method: false
}
}
The mongo database is simplicity itself, for repro purposes:
{
"Date" : "4/4/2014",
"Person" : "Bob",
"Qty1" : 45,
"Qty2" : 52
}
{
"Date" : "4/12/2014",
"Person" : "Sarah",
"Qty1" : 10,
"Qty2" : 14
}
{
"Date" : "4/12/2014",
"Person" : "Bob",
"Qty1" : 72,
"Qty2" : 33
}
{
"Date" : "5/1/2014",
"Person" : "Agnes",
"Qty1" : 24,
"Qty2" : 25
}
{
"Date" : "5/2/2014",
"Person" : "Sarah",
"Qty1" : 86,
"Qty2" : 4
}
{
"Date" : "5/6/2014",
"Person" : "Bob",
"Qty1" : 17,
"Qty2" : 4
}
loaded with `mongoimport --db mine --collection test --drop --file
c:/tmp/work1a.json`
Thank you for any pointers.
Re: Drill calcite tracing issue
Posted by Timothy Chen <tn...@gmail.com>.
I remember introducing the HepPlanner that when I worked on window
functions, probably a good idea to comment on why we actually need
that since I can't recall the exact reasons now.
Tim
On Fri, Jul 10, 2015 at 1:22 PM, Jinfeng Ni <ji...@gmail.com> wrote:
> DRILL-3156 was filed to track the calcite trace issue [1].
>
> Basically, the HepPlanner used for window function planning caused the
> tracing issue. I have a prototype patch to fix this issue. I'll try to see
> if I can get it ready for 1.2.0 release.
>
> As a workaround, if you do not use window function, you may consider
> skipping the HepPlanner findBestExp() call in
> DefaultSqlHandler.:convertToRel(SqlNode node)[2].
>
>
> 1. https://issues.apache.org/jira/browse/DRILL-3156
> 2.
> https://github.com/apache/drill/blob/master/exec/java-exec/src/main/java/org/apache/drill/exec/planner/sql/handlers/DefaultSqlHandler.java#L451
>
>
>
> On Fri, Jul 10, 2015 at 9:19 AM, George Spofford <ge...@gmail.com>
> wrote:
>
>> (If there's a better target for an issue request, please let me know!)
>>
>> While trying to understand the details Calcite rule execution, I turned on
>> the Calcite tracing per
>> https://calcite.incubator.apache.org/docs/howto.html#tracing . At that
>> point (running a query from the web UI) I get the error
>>
>> Query Failed: An Error Occurred
>> org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR:
>> AssertionError: Internal error: should never get here ...
>>
>>
>> The query is pretty straightforward:
>>
>> select Person, sum(Qty1) from mongo.mine.test group by Person
>>
>>
>>
>> A simple trial with the same settings against the Apache Calcite
>> example/csv doesn't show the same behavior. (Calcite query: SELECT DEPTNO,
>> SUM(EMPNO) FROM emps GROUP BY DEPTNO ; )
>>
>> In Drill, I'm querying against a Mongo db but the code path in the
>> exception trace doesn't immediately appear to be relevant for that. It
>> seems to happen the very first time dumpGraph is called.
>>
>> The innermost cause (in all its glory) is due to the method:
>>
>> @Override public RelOptCost computeSelfCost(RelOptPlanner planner) {
>> // HepRelMetadataProvider is supposed to intercept this
>> // and redirect to the real rels.
>> throw Util.newInternal("should never get here");
>> }
>>
>>
>> and the trace is:
>>
>> cause {
>> exception_class: "java.lang.AssertionError"
>> message: "Internal error: should never get here"
>> stack_trace {
>> class_name: "org.apache.calcite.util.Util"
>> file_name: "Util.java"
>> line_number: 775
>> method_name: "newInternal"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "org.apache.calcite.plan.hep.HepRelVertex"
>> file_name: "HepRelVertex.java"
>> line_number: 68
>> method_name: "computeSelfCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
>> file_name: "RelMdPercentageOriginalRows.java"
>> line_number: 165
>> method_name: "getNonCumulativeCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
>> file_name: "ReflectiveRelMetadataProvider.java"
>> line_number: 194
>> method_name: "invoke"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.RelMetadataQuery"
>> file_name: "RelMetadataQuery.java"
>> line_number: 115
>> method_name: "getNonCumulativeCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
>> file_name: "RelMdPercentageOriginalRows.java"
>> line_number: 151
>> method_name: "getCumulativeCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
>> file_name: "ReflectiveRelMetadataProvider.java"
>> line_number: 194
>> method_name: "invoke"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.RelMetadataQuery"
>> file_name: "RelMetadataQuery.java"
>> line_number: 101
>> method_name: "getCumulativeCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
>> file_name: "RelMdPercentageOriginalRows.java"
>> line_number: 154
>> method_name: "getCumulativeCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
>> file_name: "ReflectiveRelMetadataProvider.java"
>> line_number: 194
>> method_name: "invoke"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.calcite.rel.metadata.RelMetadataQuery"
>> file_name: "RelMetadataQuery.java"
>> line_number: 101
>> method_name: "getCumulativeCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "org.apache.calcite.plan.AbstractRelOptPlanner"
>> file_name: "AbstractRelOptPlanner.java"
>> line_number: 251
>> method_name: "getCost"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "org.apache.calcite.plan.hep.HepPlanner"
>> file_name: "HepPlanner.java"
>> line_number: 962
>> method_name: "dumpGraph"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "org.apache.calcite.plan.hep.HepPlanner"
>> file_name: "HepPlanner.java"
>> line_number: 151
>> method_name: "setRoot"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
>> file_name: "DefaultSqlHandler.java"
>> line_number: 449
>> method_name: "convertToRel"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
>> file_name: "DefaultSqlHandler.java"
>> line_number: 191
>> method_name: "validateAndConvert"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
>> file_name: "DefaultSqlHandler.java"
>> line_number: 157
>> method_name: "getPlan"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name:
>> "org.apache.drill.exec.planner.sql.DrillSqlWorker"
>> file_name: "DrillSqlWorker.java"
>> line_number: 178
>> method_name: "getPlan"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "org.apache.drill.exec.work.foreman.Foreman"
>> file_name: "Foreman.java"
>> line_number: 903
>> method_name: "runSQL"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "org.apache.drill.exec.work.foreman.Foreman"
>> file_name: "Foreman.java"
>> line_number: 242
>> method_name: "run"
>> is_native_method: false
>> }
>> stack_trace {
>> class_name: "..."
>> line_number: 0
>> method_name: "..."
>> is_native_method: false
>> }
>> }
>>
>>
>>
>> The mongo database is simplicity itself, for repro purposes:
>>
>> {
>> "Date" : "4/4/2014",
>> "Person" : "Bob",
>> "Qty1" : 45,
>> "Qty2" : 52
>> }
>> {
>> "Date" : "4/12/2014",
>> "Person" : "Sarah",
>> "Qty1" : 10,
>> "Qty2" : 14
>> }
>> {
>> "Date" : "4/12/2014",
>> "Person" : "Bob",
>> "Qty1" : 72,
>> "Qty2" : 33
>> }
>> {
>> "Date" : "5/1/2014",
>> "Person" : "Agnes",
>> "Qty1" : 24,
>> "Qty2" : 25
>> }
>> {
>> "Date" : "5/2/2014",
>> "Person" : "Sarah",
>> "Qty1" : 86,
>> "Qty2" : 4
>> }
>> {
>> "Date" : "5/6/2014",
>> "Person" : "Bob",
>> "Qty1" : 17,
>> "Qty2" : 4
>> }
>>
>> loaded with `mongoimport --db mine --collection test --drop --file
>> c:/tmp/work1a.json`
>>
>> Thank you for any pointers.
>>
Re: Drill calcite tracing issue
Posted by Jinfeng Ni <ji...@gmail.com>.
@Tim, AFAIK, the HepPlanner was introduced for window function, because
otherwise the VolcanoPlanner would hit CanNotPlan issue at that time.
@George, it would be hard to modify the code path in a production system,
unless you apply a temporary patch to do that, assuming you do not use
window function in your production system at all. Otherwise, you may
consider waiting for 1.2.0, for which we will try to get a patch to fix
this issue.
In general, the tracing feature is mainly by developer for debugging issue
related to Calcite.
On Fri, Jul 10, 2015 at 1:31 PM, George Spofford <ge...@gmail.com>
wrote:
> Thanks, will see if I can influence the code path here. Not sure how I can
> skip HepPlanner findBestExp() in production code path, but I'm in my early
> days here.
>
> Can I suggest that, for at least a smattering of query forms, that FINER
> and FINEST tracing be included in integration if not also unit tests?
>
> On Fri, Jul 10, 2015 at 1:22 PM, Jinfeng Ni <ji...@gmail.com> wrote:
>
> > DRILL-3156 was filed to track the calcite trace issue [1].
> >
> > Basically, the HepPlanner used for window function planning caused the
> > tracing issue. I have a prototype patch to fix this issue. I'll try to
> see
> > if I can get it ready for 1.2.0 release.
> >
> > As a workaround, if you do not use window function, you may consider
> > skipping the HepPlanner findBestExp() call in
> > DefaultSqlHandler.:convertToRel(SqlNode node)[2].
> >
> >
> > 1. https://issues.apache.org/jira/browse/DRILL-3156
> > 2.
> >
> >
> https://github.com/apache/drill/blob/master/exec/java-exec/src/main/java/org/apache/drill/exec/planner/sql/handlers/DefaultSqlHandler.java#L451
> >
> >
> >
> > On Fri, Jul 10, 2015 at 9:19 AM, George Spofford <ge...@gmail.com>
> > wrote:
> >
> > > (If there's a better target for an issue request, please let me know!)
> > >
> > > While trying to understand the details Calcite rule execution, I turned
> > on
> > > the Calcite tracing per
> > > https://calcite.incubator.apache.org/docs/howto.html#tracing . At that
> > > point (running a query from the web UI) I get the error
> > >
> > > Query Failed: An Error Occurred
> > > org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR:
> > > AssertionError: Internal error: should never get here ...
> > >
> > >
> > > The query is pretty straightforward:
> > >
> > > select Person, sum(Qty1) from mongo.mine.test group by Person
> > >
> > >
> > >
> > > A simple trial with the same settings against the Apache Calcite
> > > example/csv doesn't show the same behavior. (Calcite query: SELECT
> > DEPTNO,
> > > SUM(EMPNO) FROM emps GROUP BY DEPTNO ; )
> > >
> > > In Drill, I'm querying against a Mongo db but the code path in the
> > > exception trace doesn't immediately appear to be relevant for that. It
> > > seems to happen the very first time dumpGraph is called.
> > >
> > > The innermost cause (in all its glory) is due to the method:
> > >
> > > @Override public RelOptCost computeSelfCost(RelOptPlanner planner) {
> > > // HepRelMetadataProvider is supposed to intercept this
> > > // and redirect to the real rels.
> > > throw Util.newInternal("should never get here");
> > > }
> > >
> > >
> > > and the trace is:
> > >
> > > cause {
> > > exception_class: "java.lang.AssertionError"
> > > message: "Internal error: should never get here"
> > > stack_trace {
> > > class_name: "org.apache.calcite.util.Util"
> > > file_name: "Util.java"
> > > line_number: 775
> > > method_name: "newInternal"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "org.apache.calcite.plan.hep.HepRelVertex"
> > > file_name: "HepRelVertex.java"
> > > line_number: 68
> > > method_name: "computeSelfCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> > > file_name: "RelMdPercentageOriginalRows.java"
> > > line_number: 165
> > > method_name: "getNonCumulativeCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> > > file_name: "ReflectiveRelMetadataProvider.java"
> > > line_number: 194
> > > method_name: "invoke"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.RelMetadataQuery"
> > > file_name: "RelMetadataQuery.java"
> > > line_number: 115
> > > method_name: "getNonCumulativeCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> > > file_name: "RelMdPercentageOriginalRows.java"
> > > line_number: 151
> > > method_name: "getCumulativeCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> > > file_name: "ReflectiveRelMetadataProvider.java"
> > > line_number: 194
> > > method_name: "invoke"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.RelMetadataQuery"
> > > file_name: "RelMetadataQuery.java"
> > > line_number: 101
> > > method_name: "getCumulativeCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> > > file_name: "RelMdPercentageOriginalRows.java"
> > > line_number: 154
> > > method_name: "getCumulativeCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> > > file_name: "ReflectiveRelMetadataProvider.java"
> > > line_number: 194
> > > method_name: "invoke"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.calcite.rel.metadata.RelMetadataQuery"
> > > file_name: "RelMetadataQuery.java"
> > > line_number: 101
> > > method_name: "getCumulativeCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> "org.apache.calcite.plan.AbstractRelOptPlanner"
> > > file_name: "AbstractRelOptPlanner.java"
> > > line_number: 251
> > > method_name: "getCost"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "org.apache.calcite.plan.hep.HepPlanner"
> > > file_name: "HepPlanner.java"
> > > line_number: 962
> > > method_name: "dumpGraph"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "org.apache.calcite.plan.hep.HepPlanner"
> > > file_name: "HepPlanner.java"
> > > line_number: 151
> > > method_name: "setRoot"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> > > file_name: "DefaultSqlHandler.java"
> > > line_number: 449
> > > method_name: "convertToRel"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> > > file_name: "DefaultSqlHandler.java"
> > > line_number: 191
> > > method_name: "validateAndConvert"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> > > file_name: "DefaultSqlHandler.java"
> > > line_number: 157
> > > method_name: "getPlan"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name:
> > > "org.apache.drill.exec.planner.sql.DrillSqlWorker"
> > > file_name: "DrillSqlWorker.java"
> > > line_number: 178
> > > method_name: "getPlan"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "org.apache.drill.exec.work.foreman.Foreman"
> > > file_name: "Foreman.java"
> > > line_number: 903
> > > method_name: "runSQL"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "org.apache.drill.exec.work.foreman.Foreman"
> > > file_name: "Foreman.java"
> > > line_number: 242
> > > method_name: "run"
> > > is_native_method: false
> > > }
> > > stack_trace {
> > > class_name: "..."
> > > line_number: 0
> > > method_name: "..."
> > > is_native_method: false
> > > }
> > > }
> > >
> > >
> > >
> > > The mongo database is simplicity itself, for repro purposes:
> > >
> > > {
> > > "Date" : "4/4/2014",
> > > "Person" : "Bob",
> > > "Qty1" : 45,
> > > "Qty2" : 52
> > > }
> > > {
> > > "Date" : "4/12/2014",
> > > "Person" : "Sarah",
> > > "Qty1" : 10,
> > > "Qty2" : 14
> > > }
> > > {
> > > "Date" : "4/12/2014",
> > > "Person" : "Bob",
> > > "Qty1" : 72,
> > > "Qty2" : 33
> > > }
> > > {
> > > "Date" : "5/1/2014",
> > > "Person" : "Agnes",
> > > "Qty1" : 24,
> > > "Qty2" : 25
> > > }
> > > {
> > > "Date" : "5/2/2014",
> > > "Person" : "Sarah",
> > > "Qty1" : 86,
> > > "Qty2" : 4
> > > }
> > > {
> > > "Date" : "5/6/2014",
> > > "Person" : "Bob",
> > > "Qty1" : 17,
> > > "Qty2" : 4
> > > }
> > >
> > > loaded with `mongoimport --db mine --collection test --drop --file
> > > c:/tmp/work1a.json`
> > >
> > > Thank you for any pointers.
> > >
> >
>
Re: Drill calcite tracing issue
Posted by George Spofford <ge...@gmail.com>.
Thanks, will see if I can influence the code path here. Not sure how I can
skip HepPlanner findBestExp() in production code path, but I'm in my early
days here.
Can I suggest that, for at least a smattering of query forms, that FINER
and FINEST tracing be included in integration if not also unit tests?
On Fri, Jul 10, 2015 at 1:22 PM, Jinfeng Ni <ji...@gmail.com> wrote:
> DRILL-3156 was filed to track the calcite trace issue [1].
>
> Basically, the HepPlanner used for window function planning caused the
> tracing issue. I have a prototype patch to fix this issue. I'll try to see
> if I can get it ready for 1.2.0 release.
>
> As a workaround, if you do not use window function, you may consider
> skipping the HepPlanner findBestExp() call in
> DefaultSqlHandler.:convertToRel(SqlNode node)[2].
>
>
> 1. https://issues.apache.org/jira/browse/DRILL-3156
> 2.
>
> https://github.com/apache/drill/blob/master/exec/java-exec/src/main/java/org/apache/drill/exec/planner/sql/handlers/DefaultSqlHandler.java#L451
>
>
>
> On Fri, Jul 10, 2015 at 9:19 AM, George Spofford <ge...@gmail.com>
> wrote:
>
> > (If there's a better target for an issue request, please let me know!)
> >
> > While trying to understand the details Calcite rule execution, I turned
> on
> > the Calcite tracing per
> > https://calcite.incubator.apache.org/docs/howto.html#tracing . At that
> > point (running a query from the web UI) I get the error
> >
> > Query Failed: An Error Occurred
> > org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR:
> > AssertionError: Internal error: should never get here ...
> >
> >
> > The query is pretty straightforward:
> >
> > select Person, sum(Qty1) from mongo.mine.test group by Person
> >
> >
> >
> > A simple trial with the same settings against the Apache Calcite
> > example/csv doesn't show the same behavior. (Calcite query: SELECT
> DEPTNO,
> > SUM(EMPNO) FROM emps GROUP BY DEPTNO ; )
> >
> > In Drill, I'm querying against a Mongo db but the code path in the
> > exception trace doesn't immediately appear to be relevant for that. It
> > seems to happen the very first time dumpGraph is called.
> >
> > The innermost cause (in all its glory) is due to the method:
> >
> > @Override public RelOptCost computeSelfCost(RelOptPlanner planner) {
> > // HepRelMetadataProvider is supposed to intercept this
> > // and redirect to the real rels.
> > throw Util.newInternal("should never get here");
> > }
> >
> >
> > and the trace is:
> >
> > cause {
> > exception_class: "java.lang.AssertionError"
> > message: "Internal error: should never get here"
> > stack_trace {
> > class_name: "org.apache.calcite.util.Util"
> > file_name: "Util.java"
> > line_number: 775
> > method_name: "newInternal"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "org.apache.calcite.plan.hep.HepRelVertex"
> > file_name: "HepRelVertex.java"
> > line_number: 68
> > method_name: "computeSelfCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> > file_name: "RelMdPercentageOriginalRows.java"
> > line_number: 165
> > method_name: "getNonCumulativeCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> > file_name: "ReflectiveRelMetadataProvider.java"
> > line_number: 194
> > method_name: "invoke"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.RelMetadataQuery"
> > file_name: "RelMetadataQuery.java"
> > line_number: 115
> > method_name: "getNonCumulativeCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> > file_name: "RelMdPercentageOriginalRows.java"
> > line_number: 151
> > method_name: "getCumulativeCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> > file_name: "ReflectiveRelMetadataProvider.java"
> > line_number: 194
> > method_name: "invoke"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.RelMetadataQuery"
> > file_name: "RelMetadataQuery.java"
> > line_number: 101
> > method_name: "getCumulativeCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> > file_name: "RelMdPercentageOriginalRows.java"
> > line_number: 154
> > method_name: "getCumulativeCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> > file_name: "ReflectiveRelMetadataProvider.java"
> > line_number: 194
> > method_name: "invoke"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.calcite.rel.metadata.RelMetadataQuery"
> > file_name: "RelMetadataQuery.java"
> > line_number: 101
> > method_name: "getCumulativeCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "org.apache.calcite.plan.AbstractRelOptPlanner"
> > file_name: "AbstractRelOptPlanner.java"
> > line_number: 251
> > method_name: "getCost"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "org.apache.calcite.plan.hep.HepPlanner"
> > file_name: "HepPlanner.java"
> > line_number: 962
> > method_name: "dumpGraph"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "org.apache.calcite.plan.hep.HepPlanner"
> > file_name: "HepPlanner.java"
> > line_number: 151
> > method_name: "setRoot"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> > file_name: "DefaultSqlHandler.java"
> > line_number: 449
> > method_name: "convertToRel"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> > file_name: "DefaultSqlHandler.java"
> > line_number: 191
> > method_name: "validateAndConvert"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> > file_name: "DefaultSqlHandler.java"
> > line_number: 157
> > method_name: "getPlan"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name:
> > "org.apache.drill.exec.planner.sql.DrillSqlWorker"
> > file_name: "DrillSqlWorker.java"
> > line_number: 178
> > method_name: "getPlan"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "org.apache.drill.exec.work.foreman.Foreman"
> > file_name: "Foreman.java"
> > line_number: 903
> > method_name: "runSQL"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "org.apache.drill.exec.work.foreman.Foreman"
> > file_name: "Foreman.java"
> > line_number: 242
> > method_name: "run"
> > is_native_method: false
> > }
> > stack_trace {
> > class_name: "..."
> > line_number: 0
> > method_name: "..."
> > is_native_method: false
> > }
> > }
> >
> >
> >
> > The mongo database is simplicity itself, for repro purposes:
> >
> > {
> > "Date" : "4/4/2014",
> > "Person" : "Bob",
> > "Qty1" : 45,
> > "Qty2" : 52
> > }
> > {
> > "Date" : "4/12/2014",
> > "Person" : "Sarah",
> > "Qty1" : 10,
> > "Qty2" : 14
> > }
> > {
> > "Date" : "4/12/2014",
> > "Person" : "Bob",
> > "Qty1" : 72,
> > "Qty2" : 33
> > }
> > {
> > "Date" : "5/1/2014",
> > "Person" : "Agnes",
> > "Qty1" : 24,
> > "Qty2" : 25
> > }
> > {
> > "Date" : "5/2/2014",
> > "Person" : "Sarah",
> > "Qty1" : 86,
> > "Qty2" : 4
> > }
> > {
> > "Date" : "5/6/2014",
> > "Person" : "Bob",
> > "Qty1" : 17,
> > "Qty2" : 4
> > }
> >
> > loaded with `mongoimport --db mine --collection test --drop --file
> > c:/tmp/work1a.json`
> >
> > Thank you for any pointers.
> >
>
Re: Drill calcite tracing issue
Posted by Jinfeng Ni <ji...@gmail.com>.
DRILL-3156 was filed to track the calcite trace issue [1].
Basically, the HepPlanner used for window function planning caused the
tracing issue. I have a prototype patch to fix this issue. I'll try to see
if I can get it ready for 1.2.0 release.
As a workaround, if you do not use window function, you may consider
skipping the HepPlanner findBestExp() call in
DefaultSqlHandler.:convertToRel(SqlNode node)[2].
1. https://issues.apache.org/jira/browse/DRILL-3156
2.
https://github.com/apache/drill/blob/master/exec/java-exec/src/main/java/org/apache/drill/exec/planner/sql/handlers/DefaultSqlHandler.java#L451
On Fri, Jul 10, 2015 at 9:19 AM, George Spofford <ge...@gmail.com>
wrote:
> (If there's a better target for an issue request, please let me know!)
>
> While trying to understand the details Calcite rule execution, I turned on
> the Calcite tracing per
> https://calcite.incubator.apache.org/docs/howto.html#tracing . At that
> point (running a query from the web UI) I get the error
>
> Query Failed: An Error Occurred
> org.apache.drill.common.exceptions.UserRemoteException: SYSTEM ERROR:
> AssertionError: Internal error: should never get here ...
>
>
> The query is pretty straightforward:
>
> select Person, sum(Qty1) from mongo.mine.test group by Person
>
>
>
> A simple trial with the same settings against the Apache Calcite
> example/csv doesn't show the same behavior. (Calcite query: SELECT DEPTNO,
> SUM(EMPNO) FROM emps GROUP BY DEPTNO ; )
>
> In Drill, I'm querying against a Mongo db but the code path in the
> exception trace doesn't immediately appear to be relevant for that. It
> seems to happen the very first time dumpGraph is called.
>
> The innermost cause (in all its glory) is due to the method:
>
> @Override public RelOptCost computeSelfCost(RelOptPlanner planner) {
> // HepRelMetadataProvider is supposed to intercept this
> // and redirect to the real rels.
> throw Util.newInternal("should never get here");
> }
>
>
> and the trace is:
>
> cause {
> exception_class: "java.lang.AssertionError"
> message: "Internal error: should never get here"
> stack_trace {
> class_name: "org.apache.calcite.util.Util"
> file_name: "Util.java"
> line_number: 775
> method_name: "newInternal"
> is_native_method: false
> }
> stack_trace {
> class_name: "org.apache.calcite.plan.hep.HepRelVertex"
> file_name: "HepRelVertex.java"
> line_number: 68
> method_name: "computeSelfCost"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> file_name: "RelMdPercentageOriginalRows.java"
> line_number: 165
> method_name: "getNonCumulativeCost"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> file_name: "ReflectiveRelMetadataProvider.java"
> line_number: 194
> method_name: "invoke"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.RelMetadataQuery"
> file_name: "RelMetadataQuery.java"
> line_number: 115
> method_name: "getNonCumulativeCost"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> file_name: "RelMdPercentageOriginalRows.java"
> line_number: 151
> method_name: "getCumulativeCost"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> file_name: "ReflectiveRelMetadataProvider.java"
> line_number: 194
> method_name: "invoke"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.RelMetadataQuery"
> file_name: "RelMetadataQuery.java"
> line_number: 101
> method_name: "getCumulativeCost"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows"
> file_name: "RelMdPercentageOriginalRows.java"
> line_number: 154
> method_name: "getCumulativeCost"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$2$1"
> file_name: "ReflectiveRelMetadataProvider.java"
> line_number: 194
> method_name: "invoke"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.calcite.rel.metadata.RelMetadataQuery"
> file_name: "RelMetadataQuery.java"
> line_number: 101
> method_name: "getCumulativeCost"
> is_native_method: false
> }
> stack_trace {
> class_name: "org.apache.calcite.plan.AbstractRelOptPlanner"
> file_name: "AbstractRelOptPlanner.java"
> line_number: 251
> method_name: "getCost"
> is_native_method: false
> }
> stack_trace {
> class_name: "org.apache.calcite.plan.hep.HepPlanner"
> file_name: "HepPlanner.java"
> line_number: 962
> method_name: "dumpGraph"
> is_native_method: false
> }
> stack_trace {
> class_name: "org.apache.calcite.plan.hep.HepPlanner"
> file_name: "HepPlanner.java"
> line_number: 151
> method_name: "setRoot"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> file_name: "DefaultSqlHandler.java"
> line_number: 449
> method_name: "convertToRel"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> file_name: "DefaultSqlHandler.java"
> line_number: 191
> method_name: "validateAndConvert"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler"
> file_name: "DefaultSqlHandler.java"
> line_number: 157
> method_name: "getPlan"
> is_native_method: false
> }
> stack_trace {
> class_name:
> "org.apache.drill.exec.planner.sql.DrillSqlWorker"
> file_name: "DrillSqlWorker.java"
> line_number: 178
> method_name: "getPlan"
> is_native_method: false
> }
> stack_trace {
> class_name: "org.apache.drill.exec.work.foreman.Foreman"
> file_name: "Foreman.java"
> line_number: 903
> method_name: "runSQL"
> is_native_method: false
> }
> stack_trace {
> class_name: "org.apache.drill.exec.work.foreman.Foreman"
> file_name: "Foreman.java"
> line_number: 242
> method_name: "run"
> is_native_method: false
> }
> stack_trace {
> class_name: "..."
> line_number: 0
> method_name: "..."
> is_native_method: false
> }
> }
>
>
>
> The mongo database is simplicity itself, for repro purposes:
>
> {
> "Date" : "4/4/2014",
> "Person" : "Bob",
> "Qty1" : 45,
> "Qty2" : 52
> }
> {
> "Date" : "4/12/2014",
> "Person" : "Sarah",
> "Qty1" : 10,
> "Qty2" : 14
> }
> {
> "Date" : "4/12/2014",
> "Person" : "Bob",
> "Qty1" : 72,
> "Qty2" : 33
> }
> {
> "Date" : "5/1/2014",
> "Person" : "Agnes",
> "Qty1" : 24,
> "Qty2" : 25
> }
> {
> "Date" : "5/2/2014",
> "Person" : "Sarah",
> "Qty1" : 86,
> "Qty2" : 4
> }
> {
> "Date" : "5/6/2014",
> "Person" : "Bob",
> "Qty1" : 17,
> "Qty2" : 4
> }
>
> loaded with `mongoimport --db mine --collection test --drop --file
> c:/tmp/work1a.json`
>
> Thank you for any pointers.
>