Store the timing of actions in slaveapi

RESOLVED FIXED

Status

Release Engineering
General
P2
normal
RESOLVED FIXED
4 years ago
3 months ago

People

(Reporter: coop, Assigned: coop)

Tracking

(Blocks: 1 bug)

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [slaveapi])

Attachments

(1 attachment, 3 obsolete attachments)

(Assignee)

Description

4 years ago
The reboot history in slave health is currently populated from kittenherder log data. In order to properly replace this, we need to start tracking the timing of actions requested via slaveapi.

Specifically, we should be tracking:
* time request was made
* action start time
* action end time

Probably best to store these in seconds since the epoch to make date math easier.
(Assignee)

Comment 1

4 years ago
Turns out I need this before I can properly work on bug 914805.
Assignee: nobody → coop
Blocks: 914805, 939886
Priority: -- → P2
(Assignee)

Comment 2

4 years ago
bhearsum: did you see any gevent errors like the following when you were developing/testing?

https://coop.pastebin.mozilla.org/4330288

Wondering whether it's related to me working locally on a Mac instead of Linux...despite the individual steps failing, I do get a proper result at the end:

{
  "reboot": {
    "4470660944": {
      "finish_timestamp": 1392753174, 
      "request_timestamp": 1392753161, 
      "start_timestamp": 1392753168, 
      "state": 3, 
      "text": "Attempting SSH reboot...Failed.\nAttempting PDU reboot...Failed.\nSlave already has reboot bug (919801), nothing to do."
    }
  }
}

Should have a hacky patch ready for feedback soon.
Status: NEW → ASSIGNED
Flags: needinfo?(bhearsum)
(In reply to Chris Cooper [:coop] from comment #2)
> Wondering whether it's related to me working locally on a Mac instead of
> Linux...despite the individual steps failing, I do get a proper result at
> the end:

Hrm. I certainly don't hit them now, but they seem vaguely familiar. Which version of gevent are you using?

> {
>   "reboot": {
>     "4470660944": {
>       "finish_timestamp": 1392753174, 
>       "request_timestamp": 1392753161, 
>       "start_timestamp": 1392753168, 
>       "state": 3, 
>       "text": "Attempting SSH reboot...Failed.\nAttempting PDU
> reboot...Failed.\nSlave already has reboot bug (919801), nothing to do."
>     }
>   }
> }
> 
> Should have a hacky patch ready for feedback soon.

Nice!
Flags: needinfo?(bhearsum)
(Assignee)

Comment 4

4 years ago
Created attachment 8384766 [details] [diff] [review]
[slaveapi] Add timestamps to events

Asking for feedback rather than review because I'm not sure whether there's a better approach.
Attachment #8384766 - Flags: feedback?(bhearsum)
Comment on attachment 8384766 [details] [diff] [review]
[slaveapi] Add timestamps to events

Review of attachment 8384766 [details] [diff] [review]:
-----------------------------------------------------------------

This looks fine overall, but have you considered putting the timestamp generation in the Processor? I think one call to time.time() before action(), and one call afterwards would avoid the need for actions to know anything about timestamps.
Attachment #8384766 - Flags: feedback?(bhearsum) → feedback+
(Assignee)

Comment 6

4 years ago
Created attachment 8385656 [details] [diff] [review]
[slaveapi] Add timestamps to events, v2

(In reply to Ben Hearsum [:bhearsum] from comment #5)
> This looks fine overall, but have you considered putting the timestamp
> generation in the Processor? I think one call to time.time() before
> action(), and one call afterwards would avoid the need for actions to know
> anything about timestamps.

Good call, as much as I want to add timestamps by hand to every event going forward.
Attachment #8384766 - Attachment is obsolete: true
Attachment #8385656 - Flags: review?(bhearsum)
Comment on attachment 8385656 [details] [diff] [review]
[slaveapi] Add timestamps to events, v2

Review of attachment 8385656 [details] [diff] [review]:
-----------------------------------------------------------------

Awesome!
Attachment #8385656 - Flags: review?(bhearsum) → review+
(Assignee)

Comment 8

4 years ago
Comment on attachment 8385656 [details] [diff] [review]
[slaveapi] Add timestamps to events, v2

http://hg.mozilla.org/build/slaveapi/rev/07ce0c06ba96
Attachment #8385656 - Flags: checked-in+
Depends on: 979553
I'm going to be deploying this today with slaveapi 1.0.16 in Bug 979553
(Assignee)

Updated

4 years ago
Status: ASSIGNED → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
(Assignee)

Comment 10

4 years ago
If you look at https://secure.pub.build.mozilla.org/slaveapi/results right now, you'll notice that the request_timestamp corresponds to the server restart time rather than the time of the request as intended.

I don't think there's enough of a delta between start_timestamp and request_timestamp to warrant keeping both. I'll post a patch to remove request_timestamp.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
(Assignee)

Comment 11

4 years ago
Created attachment 8387920 [details] [diff] [review]
Remove request_timestamp
Attachment #8387920 - Flags: review?(bugspam.Callek)
(Assignee)

Comment 12

4 years ago
Created attachment 8387984 [details] [diff] [review]
Remove request_timestamp, v2

Small change from previous patch: we want to set the start_timestamp when we first set up the action message.
Attachment #8387920 - Attachment is obsolete: true
Attachment #8387920 - Flags: review?(bugspam.Callek)
Attachment #8387984 - Flags: review?(bugspam.Callek)
Attachment #8387984 - Flags: review?(bugspam.Callek) → review+
(Assignee)

Updated

4 years ago
No longer blocks: 914805
(In reply to Chris Cooper [:coop] [away until April 3] from comment #8)
> Comment on attachment 8385656 [details] [diff] [review]
> [slaveapi] Add timestamps to events, v2
> 
> http://hg.mozilla.org/build/slaveapi/rev/07ce0c06ba96

Somehow we lost this patch in the hg (and git) repos, not sure how thats possible, since this cset existed in my local hg repo as well... (when I spun 1.0.16)

That said, the followup cset doesn't seem to apply right now
pushed to git:

$ git push
Counting objects: 19, done.
Delta compression using up to 4 threads.
Compressing objects: 100% (10/10), done.
Writing objects: 100% (10/10), 1.31 KiB | 0 bytes/s, done.
Total 10 (delta 8), reused 0 (delta 0)
To ssh://gitolite3@git.mozilla.org/build/slaveapi.git
   ccce02a..ac585d5  master -> master

Justin@AQUARIUS /c/Sources/git/slaveapi
$ git log ccce02a..ac585d5
commit ac585d513bf9323a1ff649c113a43aac2eb9cb55
Author: Justin Wood <Callek@gmail.com>
Date:   Tue Mar 25 23:05:47 2014 -0400

    Bug 952264 - Store the timing of actions in slaveapi. r=bhearsum
(Assignee)

Comment 15

3 years ago
Comment on attachment 8387984 [details] [diff] [review]
Remove request_timestamp, v2

Don't need this patch any more. Request timestamps are working as intended now.
Attachment #8387984 - Attachment is obsolete: true
(Assignee)

Updated

3 years ago
Status: REOPENED → RESOLVED
Last Resolved: 4 years ago3 years ago
Resolution: --- → FIXED
Blocks: 1073630
Component: Tools → General
Product: Release Engineering → Release Engineering
You need to log in before you can comment on or make changes to this bug.