You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@calcite.apache.org by "Julian Hyde (JIRA)" <ji...@apache.org> on 2017/03/22 21:08:42 UTC
[jira] [Commented] (CALCITE-1720) Calcite hung on SqlPrettyWritter
after 4 or 5 successful query executions
[ https://issues.apache.org/jira/browse/CALCITE-1720?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15937130#comment-15937130 ]
Julian Hyde commented on CALCITE-1720:
--------------------------------------
Please don't address issues to me.
I recall that if you turn on certain kinds of tracing the RelNode tree gets a lot more metadata (e.g. cost estimates). Those metadata calls can be really really expensive, and there might be bugs that only show up when you turn on tracing.
> Calcite hung on SqlPrettyWritter after 4 or 5 successful query executions
> -------------------------------------------------------------------------
>
> Key: CALCITE-1720
> URL: https://issues.apache.org/jira/browse/CALCITE-1720
> Project: Calcite
> Issue Type: Bug
> Components: core
> Affects Versions: 1.11.0
> Environment: JRE v1.8, Oracle
> Reporter: Lei Wei
> Assignee: Julian Hyde
>
> Hi Julian,
> We're running POCs of calcite and avatica. We've built a standalone server to connect oracle and accept Avatica jdbc calls. We try to build a complete query flow from Client -> AvaticaJDBC -> Calcite -> Oracle. We're able to successfully send sql calls from Squirrel and a simple java test code, and received resultset successfully. However, after 4 or 5 successful calls, Calcite hung and the log stopped at SqlPrettyWritter. We couldn't run any more tests unless we restarted the standalone server.
> After we turning on the TRACE log, we saw the logs stops at SqlPrettyWriter. Has anyone ever reported this issue?
> 16:36:08.700 [qtp1831705084-18] DEBUG o.a.c.p.Prepare - Plan after physical tweaks: JdbcToEnumerableConverter: rowcount = 2.25, cumulative cost = {104.27499999999999 rows, 203.025 cpu, 0.0 io}, id = 528
> JdbcProject(NAME=[$2]): rowcount = 2.25, cumulative cost = {104.05 rows, 202.8 cpu, 0.0 io}, id = 526
> JdbcFilter(condition=[AND(=(CAST($0):DECIMAL(19, 0) NOT NULL, 2016112214460400001), =($2, 'wenTest_2'))]): rowcount = 2.25, cumulative cost = {102.25 rows, 201.0 cpu, 0.0 io}, id = 524
> JdbcTableScan(table=[[CDS_META_DEV, CDS_APPLICATION]]): rowcount = 100.0, cumulative cost = {100.0 rows, 101.0 cpu, 0.0 io}, id = 424
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'SELECT'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '"NAME"'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'FROM'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '"CDS_META_DEV"'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '.'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '"CDS_APPLICATION"'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'WHERE'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'CAST'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '('; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '"APPLICATION_ID"'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'AS'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'DECIMAL'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '('; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '0'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ','; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '0'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ')'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ')'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '='; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '2016112214460400001'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is 'AND'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '"NAME"'; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is '='; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''wenTest_2''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
> 16:36:08.701 [qtp1831705084-18] TRACE o.a.c.s.p.SqlPrettyWriter - Token is ''; result is false
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)