Chinmay Kulkarni created PHOENIX-5981:
-----------------------------------------
Summary: 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
Fix For: 4.16.0
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)
