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

Karan Mehta commented on PHOENIX-3799:
--------------------------------------

Hey Marco, 
Could you confirm the Phoenix version number as well as HTrace version number 
that it is using? Till now, Phoenix uses the version of HTrace which doesn't 
throw an exception on this error.

[~samarthjain] I looked into the issue. For a union query, we try tracing 
individual iterators for all the queries involved. Since this happens in a 
single thread, the parent span of each new iterator is equal to previous 
iterator's span, but in fact it should not be tied to it, since both of them 
are independent iterators altogether. For example, in the query {{SELECT K FROM 
TABLEA UNION ALL SELECT K FROM TABLEB UNION ALL SELECT K FROM TABLEC}}, three 
separate iterators are created for all the three queries involved in the same 
thread. Hence, the spans look something like this
{code}
Parent Span
  + TABLEA Iterator Span
      + TABLEB Iterator Span
          + TABLEC Iterator Span
                + HBase Spans for TABLEC
                + HBase Spans for TABLEB
                + HBase Spans for TABLEA
{code}
and hence when these iterators are closed, the span in threadlocal will not 
match the span in the current scope, resulting in this exception. 

What we really want is something like this
{code}
Parent Span
  + TABLEA Iterator Span
      + HBase Spans for TABLEA
  + TABLEB Iterator Span
      + HBase Spans for TABLEA
  + TABLEC Iterator Span
      + HBase Spans for TABLEA
{code}
However such a thing is not possible unless we initialize the iterators 
parallely. Please suggest as to how we should handle this. For now, we don't 
have any parent span with a TraceScope of complete query. 

> Error on tracing query with "union all" 
> ----------------------------------------
>
>                 Key: PHOENIX-3799
>                 URL: https://issues.apache.org/jira/browse/PHOENIX-3799
>             Project: Phoenix
>          Issue Type: Bug
>    Affects Versions: 4.7.0
>         Environment: Phoenix on Cloudera 5.8
>            Reporter: Marco
>              Labels: TRACING
>
> When i try to enable tracing for query with a "union all" clause, I receive 
> an error  and the process stop the execution.
> Error: 
> 0: jdbc:phoenix:xxxxxxxxx> select sum(1) as num from (
> . . . . . . . . . . . . . . > select count(1) as num from my_tab where 
> meas_ym ='201601'
> . . . . . . . . . . . . . . > union all
> . . . . . . . . . . . . . . > select count(1) as num from my_tab where 
> meas_ym ='201602');
> 17/04/20 15:39:38 ERROR htrace.Tracer: Tried to close trace span 
> {"i":"7a2caddba3cc1d5d","s":"f262306696ff7120","b":1492702777540,"d":"Creating
>  basic query for [CLIENT 10-CHUNK 9560319 ROWS 2516584015 BYTES PARALLEL 
> 1-WAY RANGE SCAN OVER MY_TAB ['201601'],     SERVER FILTER BY FIRST KEY ONLY, 
>     SERVER AGGREGATE INTO SINGLE 
> ROW]","p":["f6e9e018136584b0"],"t":[{"t":1492702777542,"m":"First request 
> completed"}]} but it is not the current span for the main thread.  You have 
> probably forgotten to close or detach 
> {"i":"7a2caddba3cc1d5d","s":"f1a3a546476f1c94","b":1492702777541,"d":"Creating
>  basic query for [CLIENT 36-CHUNK 40590914 ROWS 10380911994 BYTES PARALLEL 
> 1-WAY RANGE SCAN OVER MY_TAB ['201602'],     SERVER FILTER BY FIRST KEY ONLY, 
>     SERVER AGGREGATE INTO SINGLE ROW]","p":["f262306696ff7120"]}
> java.lang.RuntimeException: Tried to close trace span 
> {"i":"7a2caddba3cc1d5d","s":"f262306696ff7120","b":1492702777540,"d":"Creating
>  basic query for [CLIENT 10-CHUNK 9560319 ROWS 2516584015 BYTES PARALLEL 
> 1-WAY RANGE SCAN OVER MY_TAB ['201601'],     SERVER FILTER BY FIRST KEY ONLY, 
>     SERVER AGGREGATE INTO SINGLE 
> ROW]","p":["f6e9e018136584b0"],"t":[{"t":1492702777542,"m":"First request 
> completed"}]} but it is not the current span for the main thread.  You have 
> probably forgotten to close or detach 
> {"i":"7a2caddba3cc1d5d","s":"f1a3a546476f1c94","b":1492702777541,"d":"Creating
>  basic query for [CLIENT 36-CHUNK 40590914 ROWS 10380911994 BYTES PARALLEL 
> 1-WAY RANGE SCAN OVER MY_TAB ['201602'],     SERVER FILTER BY FIRST KEY ONLY, 
>     SERVER AGGREGATE INTO SINGLE ROW]","p":["f262306696ff7120"]}
>         at org.apache.htrace.Tracer.clientError(Tracer.java:60)
>         at org.apache.htrace.TraceScope.close(TraceScope.java:90)
>         at 
> org.apache.phoenix.trace.TracingIterator.close(TracingIterator.java:46)
>         at 
> org.apache.phoenix.iterate.DelegateResultIterator.close(DelegateResultIterator.java:39)
>         at 
> org.apache.phoenix.iterate.LookAheadResultIterator$1.close(LookAheadResultIterator.java:42)
>         at 
> org.apache.phoenix.iterate.ConcatResultIterator.currentIterator(ConcatResultIterator.java:104)
>         at 
> org.apache.phoenix.iterate.ConcatResultIterator.next(ConcatResultIterator.java:117)
>         at 
> org.apache.phoenix.iterate.DelegateResultIterator.next(DelegateResultIterator.java:44)
>         at 
> org.apache.phoenix.execute.TupleProjectionPlan$1.next(TupleProjectionPlan.java:67)
>         at 
> org.apache.phoenix.iterate.LookAheadResultIterator$1.advance(LookAheadResultIterator.java:47)
>         at 
> org.apache.phoenix.iterate.LookAheadResultIterator.next(LookAheadResultIterator.java:67)
>         at 
> org.apache.phoenix.iterate.BaseGroupedAggregatingResultIterator.next(BaseGroupedAggregatingResultIterator.java:64)
>         at 
> org.apache.phoenix.iterate.LookAheadResultIterator$1.advance(LookAheadResultIterator.java:47)
>         at 
> org.apache.phoenix.iterate.LookAheadResultIterator.init(LookAheadResultIterator.java:59)
>         at 
> org.apache.phoenix.iterate.LookAheadResultIterator.next(LookAheadResultIterator.java:65)
>         at 
> org.apache.phoenix.iterate.BaseGroupedAggregatingResultIterator.next(BaseGroupedAggregatingResultIterator.java:64)
>         at 
> org.apache.phoenix.iterate.UngroupedAggregatingResultIterator.next(UngroupedAggregatingResultIterator.java:39)
>         at 
> org.apache.phoenix.jdbc.PhoenixResultSet.next(PhoenixResultSet.java:778)
>         at sqlline.BufferedRows.<init>(BufferedRows.java:37)
>         at sqlline.SqlLine.print(SqlLine.java:1650)
>         at sqlline.Commands.execute(Commands.java:833)
>         at sqlline.Commands.sql(Commands.java:732)
>         at sqlline.SqlLine.dispatch(SqlLine.java:808)
>         at sqlline.SqlLine.begin(SqlLine.java:681)
>         at sqlline.SqlLine.start(SqlLine.java:398)
>         at sqlline.SqlLine.main(SqlLine.java:292)
> Without tracing, the query works fine:
> 0: jdbc:phoenix:xxxxxxxxx> select sum(1) as num from (
> . . . . . . . . . . . . . . > select count(1) as num from my_tab where 
> meas_ym ='201601'
> . . . . . . . . . . . . . . > union all
> . . . . . . . . . . . . . . > select count(1) as num from my_tab where 
> meas_ym ='201602');
> +------+
> | NUM  |
> +------+
> | 2    |
> +------+
> 1 row selected (8.507 seconds)



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

Reply via email to