[PHOENIX-5981] Wrong multiple counting of resultSetTimeMs and wallclockTimeMs in OverallQueryMetrics

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 5.0.0, 4.15.0
• Fix Version/s: 5.1.0, 4.16.0
• Labels: metrics phoenix-hardening quality-improvement
• Assignee: Chinmay Kulkarni
• Reporter: Chinmay Kulkarni
• Created: 30/Jun/20 02:12
• Updated: 16/Jul/20 22:44
• Resolved: 16/Jul/20 19:23

Description

We update wallClockTimeMS and resultSetTimeMS when we reach the last row in our ResultSet iterations (see this). However, this is also called inside PhoenixResultSet.close(), see this.

The problem is, these calls in-turn add elapsedTime again (endQuery and stopResultsetWatch) 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.