SQL Lab: Query History: Duration column shows some nonsense durations (expected only duration of run)

praveer38 commented 3 days ago

Bug description

On the SQL Lab’s “Query History” tab, the “Duration column:

expected: it should show only execution duration for the query (i.e. under a second for simple queries)

actual: it is showing some real values along with some unexpected values as shown in the video and screenshot.

Steps to Reproduce

Go to SQL Lab
Create a query
Run the query (and variations of it) multiple times
Click the “Query History” tab
The “Duration” column will show a fraction of a second for each query
In the Results column, click “View”
Close the query view

Screenshots/recordings

https://github.com/user-attachments/assets/6c952b9c-f612-4478-996e-ab2531d2c41a

Superset version

4.0.2

Python version

3.9

Node version

16

Browser

Chrome

Additional context

No response

Checklist

[X] I have searched Superset docs and Slack and didn't find a solution to my problem.
[X] I have searched the GitHub issue tracker and didn't find a similar bug report.
[X] I have checked Superset's logs for errors and if I found a relevant Python stacktrace, I included it here as text in the "additional context" section.

dosubot[bot] commented 3 days ago

The "Duration" column in the SQL Lab's "Query History" tab shows unexpected values because it calculates the duration using both the start and end timestamps of the query execution. The duration is computed using the fDuration function, which takes q.startDttm and q.endDttm as inputs. This means that the duration reflects the total time from when the query started to when it ended, which may include time spent in states other than just execution, such as queuing or waiting for resources ^[1].

The fDuration function calculates the duration by subtracting the start time from the end time to get the difference in milliseconds, then formats it as a UTC time string ^[2].

The possible states a query can be in during its lifecycle include Started, Stopped, Failed, Pending, Running, Scheduled, Success, Fetching, and TimedOut. The startDttm is set when the query enters the Started state, and endDttm is set when the query reaches a concluded state, such as Stopped, Failed, Success, or TimedOut ^[3].

To continue talking to Dosu, mention @dosu.

rusackas commented 3 days ago

Here's where that value is calculated/displayed, if you want to debug things a bit (printing out the times used in the calculation, etc) https://github.com/apache/superset/blob/24b8a94c2ce4d21c65caa076bdc54ba61635be85/superset-frontend/src/pages/QueryHistoryList/index.tsx#L232-L249

apache / superset