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

Pranavan commented on PHOENIX-2178:
-----------------------------------

Hi James and Mujtaba Chohan. I found the solution for this. 

The difference is huge because the wall clock is calculating the actual time 
where as sum(endtime - starttime) is calculating the sum of the differences. 
When it comes to difference, most of the readBlock traces will take nano 
seconds. There is a small fraction of readBlock traces which end up with the 
gap of 1 millisecond. 

This the code segment which assigns start and end time. 
builder.addCounter(Interns.info(START.traceName, EMPTY_STRING), 
span.getStartTimeMillis());
builder.addCounter(Interns.info(END.traceName, EMPTY_STRING), 
span.getStopTimeMillis());


The solution is to store the nanotime. This will eventually lead to get rid of 
round of errors which we are actually facing now. It will not change the DDL of 
Tracing table, but the content will be nanotime.

> Tracing - total time listed for a certain trace does not correlate with query 
> wall clock time
> ---------------------------------------------------------------------------------------------
>
>                 Key: PHOENIX-2178
>                 URL: https://issues.apache.org/jira/browse/PHOENIX-2178
>             Project: Phoenix
>          Issue Type: Sub-task
>    Affects Versions: 4.5.0
>            Reporter: Mujtaba Chohan
>              Labels: gsoc2016, tracing
>
> Wall clock for a count * takes over a large table takes 30000+ms however 
> total sum(end_time - start_time) is less than 250ms for trace_id generated 
> for this count * query.
> {code}
> Output of trace table:
> select sum(end_time  - start_time),count(*), description from 
> SYSTEM.TRACING_STATS WHERE TRACE_ID=X group by description;
> +------------------------------------------+------------------------------------------+------------------------------------------+
> |       SUM((END_TIME - START_TIME))       |                 COUNT(1)         
>         |               DESCRIPTION                |
> +------------------------------------------+------------------------------------------+------------------------------------------+
> | 0                                        | 3                                
>         | ClientService.Scan                       |
> | 240                                      | 253879                           
>         | HFileReaderV2.readBlock                  |
> | 1                                        | 1                                
>         | Scanner opened on server                 |
> +------------------------------------------+------------------------------------------+------------------------------------------+
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to