Page MenuHomePhabricator

Include query execution time
Closed, ResolvedPublic

Assigned To
Authored By
Slaporte
Feb 13 2016, 8:59 PM
Tokens
"Like" token, awarded by zhuyifei1999."Like" token, awarded by Lokal_Profil."Like" token, awarded by Yamaha5."Like" token, awarded by matej_suchanek."Like" token, awarded by He7d3r."Haypence" token, awarded by XXN.

Description

Add in worker.py the count of query running time (delta of before/after execution timers) and store it in a new column of the query_run table.
Then show this in query run info api endpoint then in the nunchunk-created interface.

Event Timeline

Slaporte raised the priority of this task from to Needs Triage.
Slaporte updated the task description. (Show Details)
Slaporte added a project: Quarry.
Slaporte added subscribers: Slaporte, mahmoud, yuvipanda.

I don't seen any benefit of adding the pending time (only for monitoring purposes?), feel free to explain why it's needed

The only advantage would be to know if queries are getting stuck in "pending" mode for too long. It used to be an issue a while back but hasn't been for a long time.

Change 465659 had a related patch set uploaded (by Framawiki; owner: Framawiki):
[analytics/quarry/web@master] Store and show query execution time

https://gerrit.wikimedia.org/r/465659

Change 465659 merged by jenkins-bot:
[analytics/quarry/web@master] Store and show query execution time

https://gerrit.wikimedia.org/r/465659

Mentioned in SAL (#wikimedia-cloud) [2018-10-15T18:52:53Z] <framawiki> deployed c1dfde7 on quarry-web-01, quarry-worker-0{1,2} T126888

Framawiki claimed this task.

Queries now show execution time near the resultset on the status page.

@Framawiki: I think using using the time of cur.execute to get the execution time is flawed. There is no way this query could finish in 0.01 seconds.

Tested with https://quarry.wmflabs.org/query/30399:

SELECT SLEEP(10);

waits for completion in cur.execute(), while

USE enwiki_p;
SELECT SLEEP(10);

doesn't.

It would be nice to have both execute time and combined execute + fetch time, as the latter more accurately represents the an application would spend waiting (which would really help with prototyping). Also, thanks for this!

I guess we could just change to execute + fetch + store. Beware though, that can be heavily lagged due to the use of SQLite on NFS for storing the results.

I currently don't see a way of forcing pymysql to finish the query before returning from cur.execute, without putting all the results into memory (which we kinda do anyways)

Change 468826 had a related patch set uploaded (by Framawiki; owner: Framawiki):
[analytics/quarry/web@master] worker.py: fix running time calculation points

https://gerrit.wikimedia.org/r/468826

Thanks for checking that it works @zhuyifei1999 ! I should have tested with sleep, that's how I see that I'm a volunteer here :)
The patch above move the stoppoint after all the worker process (execute + fetch + store).

Change 468826 merged by jenkins-bot:
[analytics/quarry/web@master] worker.py: fix running time calculation points

https://gerrit.wikimedia.org/r/468826