[buildbot] Track the amount of time a change sits in the queue before buildbot starts building the change

RESOLVED FIXED in Q3 11 - Serrano

Status

P2
major
RESOLVED FIXED
9 years ago
8 years ago

People

(Reporter: brbaker, Assigned: jsudduth)

Tracking

unspecified
Q3 11 - Serrano
Bug Flags:
in-testsuite -
flashplayer-qrb +
flashplayer-triage +

Details

Attachments

(1 attachment, 5 obsolete attachments)

(Reporter)

Description

9 years ago
We want to know for each change in tamarin-redux, argo and sandbox, how long does a change sit in the buildbot queue before it is submitted into the build.

One easy way to implement this would be to look at the <buildbot>/changes/processed directory and look at the timestamps on the build request files.

request time = create date
processed time = modified date

If the modified date is not changed when the file is moved from "pending" into "processed" then the watcher_trigger.py script (which moves the request file) can be modified to touch the file when it moves it.
Flags: in-testsuite-
Flags: flashplayer-triage+
Flags: flashplayer-qrb?

Comment 1

9 years ago
Info should be logged to csv for later mining.  Columns could include date, branch (tr, tr-argo, sandbox, etc),  queue-time, revision
Assignee: nobody → jsudduth
Flags: flashplayer-qrb? → flashplayer-qrb+
Target Milestone: --- → flash10.2

Updated

9 years ago
Severity: normal → major
Priority: -- → P2

Updated

9 years ago
Status: NEW → ASSIGNED
(Assignee)

Comment 2

9 years ago
Created attachment 442024 [details] [diff] [review]
Pending build queue wait time logging.

Please review the changes in the processBatchedChanges function especially carefully as it wasn't possible to test this code well (lines 142-148).
Attachment #442024 - Flags: review?(cpeyer)
Attachment #442024 - Flags: feedback?(brbaker)
(Reporter)

Comment 3

9 years ago
Comment on attachment 442024 [details] [diff] [review]
Pending build queue wait time logging.

- call to logQueueTimes() for the sandbox should only pass /change/ instead of priority3files as only ONE change file will be processed and not all of them:
   logQueueTimes(3, change, "sandbox")

+ Please comment out/remove this line in the except block, this was causing the process to crash and I have tweaked the current deployed version of the script but have NOT pushed the change back into source (my bad)
"log(sys.exc_info())"

+ wondering about the usefulness of the last column in the data. I assume that the expect reporting of this data will be in minutes so might as well just log that so that it can be used directly. Since full timestamps are being recorded somebody could still determine to the second the amount of time a request sat in the queue
Attachment #442024 - Flags: feedback?(brbaker) → feedback+

Comment 4

9 years ago
Is this ready to go?
(Assignee)

Comment 5

9 years ago
I've made the first two changes Brent suggested and am awaiting review from Chris. I'm not sure how to incorporate the expect data, so I left the last column as is for now.

Comment 6

9 years ago
How often will the csv be updated?  In real time?  Will it generally readable or locked?  I'd like to be able to use the csv it in a confluence chart wrapped in a cache tag.

Comment 7

9 years ago
Comment on attachment 442024 [details] [diff] [review]
Pending build queue wait time logging.

I think that we should record total elapsed time between creating and processed in seconds instead of the hours/min/sec format.  That would make it easier to calculate and process/display the data programatically (though I guess we can just compute that from the current format).

Other than that and Brents suggestions - r+
Attachment #442024 - Flags: review?(cpeyer) → review+

Comment 8

9 years ago
From the confluence chart and csv perspective, I can't do any operations on the values.  Could there be a column for seconds (as Chris suggests) and another for minutes (maybe with a single decimal precision)?  The wiki chart would then use the data as-is.

I do agree that the value should be a number and not need to be parsed.
(Assignee)

Comment 9

9 years ago
I've made the first two changes Brent suggested and am awaiting review from Chris. I'm not sure how to incorporate the expect data, so I left the last column as is for now.
(Assignee)

Comment 10

9 years ago
Created attachment 442205 [details] [diff] [review]
Changes to pending build queue wait time logging.

- Added a field header when the log file is created.
- The queue log time file will be updated every time any priority 1, 2, or 3 change files are moved from the pending to the processed queue. It should be always be unlocked and readable, except maybe when it's being written to (which should be very fast).
- Changed the last field, which was hours:minutes:seconds, to two fields, minutes and seconds. Minutes has single decimal precision.
Attachment #442024 - Attachment is obsolete: true
Attachment #442205 - Flags: review?(cpeyer)
Attachment #442205 - Flags: feedback?(brbaker)
(Reporter)

Updated

9 years ago
Attachment #442205 - Flags: feedback?(brbaker) → feedback+

Comment 11

9 years ago
Comment on attachment 442205 [details] [diff] [review]
Changes to pending build queue wait time logging.

looks good.  only minor thing is to split some of the longer lines into two lines.
Attachment #442205 - Flags: review?(cpeyer) → review+

Comment 12

9 years ago
One more thing: the script should copy the log file after each update (or store it) in e/AVMTeam/buildbot/master-tamarin-redux/public_html/analytics so that the file is http accessible.
(Assignee)

Comment 13

9 years ago
Created attachment 442479 [details] [diff] [review]
Copy queue times log to where it's available via http

Shortened some long lines, adding copy to a folder accessible via http.
Attachment #442205 - Attachment is obsolete: true
Attachment #442479 - Flags: review?(cpeyer)

Updated

9 years ago
Attachment #442479 - Flags: review?(cpeyer) → review+

Comment 14

9 years ago
Comment on attachment 442479 [details] [diff] [review]
Copy queue times log to where it's available via http

+    shutil.copy(QUEUELOGTIME, MASTER_ROOT+'/public_html/analytics')

Shouldn't that be QUEUETIMELOG?

Also recommend queuetimes.log be named queuetimes.csv for clarity
(Assignee)

Comment 15

9 years ago
Created attachment 442490 [details] [diff] [review]
Update to 442479

Added a boolean to config files so queue time logging is not done for the asc, perf and deep cycles. Corrected QUEUELOGTIME to QUEUETIMELOG. Changed log file name to use "csv" extension.
Attachment #442479 - Attachment is obsolete: true
Attachment #442490 - Flags: review?(cpeyer)
(Assignee)

Comment 16

9 years ago
Created attachment 442492 [details] [diff] [review]
Removed unwanted readme.txt changes from patch file.
Attachment #442490 - Attachment is obsolete: true
Attachment #442492 - Flags: review?(cpeyer)
Attachment #442490 - Flags: review?(cpeyer)

Updated

9 years ago
Attachment #442492 - Attachment is patch: true
Attachment #442492 - Attachment mime type: application/octet-stream → text/plain
Attachment #442492 - Flags: review?(cpeyer) → review+

Comment 17

9 years ago
pushed to qe repo: http://asteam/hg/qe/rev/e2747142c600
and updated the in the master/scripts dir on playercore
Status: ASSIGNED → RESOLVED
Last Resolved: 9 years ago
Resolution: --- → FIXED

Comment 18

9 years ago
+                fields_msg = "change-file,priority,branch,creation time,processed time,minutes in queue,\
+                                seconds in queue"

Since quoted, this space indenting results in 32 spaces in the column listing row.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---

Comment 19

9 years ago
I don't think the priority column is right.  I'm seeing sandbox builds listed as 3 and redux listed as 2, when I think it is actually the opposite.  Please confirm.
(Assignee)

Comment 20

9 years ago
It's a bit misleading because the numbers used for the change file extensions don't actually determine how watcher_trigger.py prioritizes its runs. The way they're parsed out in watcher_trigger.py lines 205-227, the sandbox builds get higher prioritization by the order of the if and elif statements, with sandbox being run before redux if a sandbox change file is present.
(Assignee)

Comment 21

9 years ago
Created attachment 443437 [details] [diff] [review]
Remove line continuation on line 170 which added extra spaces before the last field of the csv file
Attachment #442492 - Attachment is obsolete: true
Attachment #443437 - Flags: review?(cpeyer)
(Assignee)

Comment 22

8 years ago
Neglected to close this after fixing the line continuation problem.
Status: REOPENED → RESOLVED
Last Resolved: 9 years ago9 years ago
Resolution: --- → FIXED

Updated

8 years ago
Attachment #443437 - Flags: review?(cpeyer) → review+
You need to log in before you can comment on or make changes to this bug.