You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@phoenix.apache.org by "Chinmay Kulkarni (Jira)" <ji...@apache.org> on 2020/07/01 17:52:00 UTC

[jira] [Updated] (PHOENIX-5981) Wrong multiple counting of resultSetTimeMs and wallclockTimeMs in OverallQueryMetrics

     [ https://issues.apache.org/jira/browse/PHOENIX-5981?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Chinmay Kulkarni updated PHOENIX-5981:
--------------------------------------
    Attachment: PHOENIX-5981-4.x-v1.patch

> Wrong multiple counting of resultSetTimeMs and wallclockTimeMs in OverallQueryMetrics
> -------------------------------------------------------------------------------------
>
>                 Key: PHOENIX-5981
>                 URL: https://issues.apache.org/jira/browse/PHOENIX-5981
>             Project: Phoenix
>          Issue Type: Bug
>    Affects Versions: 4.15.0
>            Reporter: Chinmay Kulkarni
>            Assignee: Chinmay Kulkarni
>            Priority: Major
>              Labels: metrics, phoenix-hardening, quality-improvement
>             Fix For: 4.16.0
>
>         Attachments: PHOENIX-5981-4.x-v1.patch, PHOENIX-5981-master-v1.patch
>
>          Time Spent: 20m
>  Remaining Estimate: 0h
>
> We update wallClockTimeMS and resultSetTimeMS when we reach the last row in our ResultSet iterations (see [this|https://github.com/apache/phoenix/blob/dcc88af8acc2ba8df10d2e9d498ab3646fdf0a78/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixResultSet.java#L878-L881]). However, this is also called inside PhoenixResultSet.close(), see [this|https://github.com/apache/phoenix/blob/dcc88af8acc2ba8df10d2e9d498ab3646fdf0a78/phoenix-core/src/main/java/org/apache/phoenix/jdbc/PhoenixResultSet.java#L214-L215].
> The problem is, these calls in-turn add elapsedTime again ([endQuery|https://github.com/apache/phoenix/blob/dcc88af8acc2ba8df10d2e9d498ab3646fdf0a78/phoenix-core/src/main/java/org/apache/phoenix/monitoring/OverAllQueryMetrics.java#L86] and [stopResultsetWatch|https://github.com/apache/phoenix/blob/dcc88af8acc2ba8df10d2e9d498ab3646fdf0a78/phoenix-core/src/main/java/org/apache/phoenix/monitoring/OverAllQueryMetrics.java#L95]) and so these metrics get 2X the value they should. Ideally we should change the metrics only if the stopWatch was running before calling stopWatch.stop or else we will count it multiple times.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)