1448204 - Record vcs metrics

Status: RESOLVED FIXED

(Developer Services :: Mercurial: robustcheckout, enhancement)

Description

[Gregory Szorc [:gps]]

We currently have little to no metrics for how much time Firefox CI is spending doing version control operations. The data is there in the logs - at least for Taskcluster tasks using run-task. But we don't ingest it as metrics.

We should fix that.

Comment 1

[Gregory Szorc [:gps]]

Attachment: robustcheckout: record metrics for operations (bug 1448204);

This commit teaches `hg robustcheckout` to record times of various
operations.

We assign each operation a name. Then we map that name to a "suite"
in Perfherder terminology.

We aggregate the various operations and turn them into a
PERFHERDER_DATA blob. This blob is recognized by Treeherder and
ActiveData as metrics data. This means we can graph the data,
query it for statistics, etc.

Metrics are grouped by Taskcluster instance type. This feels like the
most natural grouping to me. Obviously different EC2 instances will
have different performance characteristics. But behavior of a specific
EC2 instance should hopefully be relatively stable - at least for some
operations.

I'm not sure how much variance there will be in this data. I don't want
sheriffs to be concerned about changes. So, Perfherder alerts have been
disabled for all metrics for the time being.

Hopefully the only non-trivial part of this commit is the declaration
of the "vcs" framework. I /think/ various downstream consumers need
to be taught about the introduction of new Perfherder "frameworks."
But I'm not sure about that.

Review commit: https://reviewboard.mozilla.org/r/230484/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/230484/

Comment 2

[:glob ✱]

Comment on attachment 8961616 [details]
robustcheckout: record metrics for operations (bug 1448204);

https://reviewboard.mozilla.org/r/230484/#review235986

lgtm

::: hgext/robustcheckout/tests/test-perfherder.t:17
(Diff revision 1)
> +  added 3 changesets with 3 changes to 1 files (+1 heads)
> +  searching for changes
> +  no changes found
> +  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
> +  updated to 5d6cdc75a09bcccf76f9339a28e1d89360c59dce
> +  PERFHERDER_DATA: {"framework": {"name": "vcs"}, "suites": \[{"extraOptions": \["c5.4xlarge"\], "lowerIsBetter": true, "name": "clone", "shouldAlert": false, "subtests": \[\], "value": \d+\.\d+}, {"extraOptions": \["c5.4xlarge"\], "lowerIsBetter": true, "name": "update", "shouldAlert": false, "subtests": \[\], "value": \d+\.\d+}, {"extraOptions": \["c5.4xlarge"\], "lowerIsBetter": true, "name": "overall", "shouldAlert": false, "subtests": \[\], "value": \d+\.\d+}]} (re)

escape the period in c5.4xlarge (shouldn't matter in practice, but consistency is nice)

Comment 3

[Cameron Dawson [:camd]]

Comment on attachment 8961616 [details]
robustcheckout: record metrics for operations (bug 1448204);

Hmm, this is quite a ways out of my wheelhouse, so I'm not a good person to check correctness here.  Will, would you be up for taking a look?

Comment 4

[Gregory Szorc [:gps]]

The review I want from Treeherder/Perfherder/ActiveData is more a rubber stamp that it is OK to introduce a new "vcs" framework for PERFHERDER_DATA. I can't recall if we can just start writing data for new namespaces or whether consumers have an allow list that needs updating. I don't want to deploy this and have it trigger a bunch of warnings or something.

Comment 5

[William Lachance (:wlach)]

Comment on attachment 8961616 [details]
robustcheckout: record metrics for operations (bug 1448204);

Yes, we would need to add a new performance framework to the list of fixtures for this to show up (https://github.com/mozilla/treeherder/blob/master/treeherder/perf/fixtures/performance_framework.json).

Under what circumstances would a job be collecting this information? Even if it's just builds, this seems highly likely to generate more datapoints than would be easily visible in perfherder graphs (i.e. the user interface would grind to a halt). 

Since afaict this is tracking data that depends on infrastructure changes instead of source revision, I think this data would be better submitted to a tool like influxdb and visualized with grafana -- I believe the taskcluster or release engineering team (forget which) already has something like this set up.

Comment 6

[Gregory Szorc [:gps]]

All tasks using a version control checkout would be producing this data. Today, that's decision, docker image build, build, source test, and a handful of others. Most test tasks are notably absent. In the future, we're trending towards all tasks running from a source checkout.

I agree Perfherder may not be the most appropriate receptacle for this data. Honestly, I care more about ActiveData, as it would allow me to query for things like "give me the percentage of tasks that had a VCS store cache hit" or "what's the median time that tasks took to obtain a VCS checkout this week."

PERFHERDER_DATA seems to be a useful hammer for easily having this data ingested. That's why I used it. I'd prefer to avoid complexity with a service like influxdb. But if there's a better way to get this data ingested into ActiveData, I'm all ears. Maybe we could teach ActiveData to look for a new metrics syntax that isn't PERFHERDER_DATA? That would be changed at https://github.com/klahnakoski/ActiveData-ETL/blob/dev/activedata_etl/transforms/pulse_block_to_perfherder_logs.py. Actually, looking at that code, it appears to want an " INFO" prefix on PERFHERDER_DATA lines. So maybe ActiveData won't "just work" like I thought it would. ekyle?

Comment 7

[Gregory Szorc [:gps]]

FWIW https://treeherder.mozilla.org/#/jobs?repo=try&revision=bf1db1d99093786c8ab77332d8a13a6077fc7dcd is a Try push with this change active. We can see the PERFHERDER_DATA line at e.g. https://treeherder.mozilla.org/logviewer.html#?job_id=169933997&repo=try&lineNumber=244.

Comment 8

[William Lachance (:wlach)]

I have no problem with adding a line saying PERFHERDER_DATA per se -- so long as there is no framework for "vcs" in treeherder, it will be silently ignored from the perspective of that tool. My main point was that I don't think perfherder is a good visualization tool for this volume of data and that you'd do well to use some kind of off-the-shelf tool oriented around monitoring systems in operation (as mentioned, I thought we already had an instance of influx/grafana somewhere, but I might be out of date).

Comment 9

[Kyle Lahnakoski [:ekyle]]

ActiveData will ingest the perf results, no matter the framework.  r+

Comment 10

[Kyle Lahnakoski [:ekyle]]

When this code runs, and a PERFHERDER_DATA line s created, please post a link to the log artifact here.  I will make sure it gets into ActiveData (and work around any expected prefix that currently exists).

Comment 11

[Kyle Lahnakoski [:ekyle]]

I am now seeing the link above.  I will make sure the ETL pipeline can capture it.

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/hgcustom/version-control-tools/rev/f0c7808d6c00
robustcheckout: record metrics for operations ; r=glob

Comment 13

[Gregory Szorc [:gps]]

I'll get this deployed to Firefox CI in bug 1448438.

I consider this somewhat alpha at this time. I imagine we'll want to tweak things a bit more. e.g. I'd like to potentially differentiate things by sparse profile, platform, etc. Let's get some data first and see where the cracks are.

Comment 14

[Kyle Lahnakoski [:ekyle]]

All VCS records are arriving in ActiveData starting Apr3. Before that time it seems harnesses were running the code, and ActiveData picked up those PERFHERDER artifacts too. This is still the case, so beware these records are coming from more than one context.

Here is an example of one action over the past month: 
https://activedata.allizom.org/tools/query.html#query_id=cST259cU

Here are all the actions for the past week 
https://activedata.allizom.org/tools/query.html#query_id=9WoxGC2P

Comment 15

[Gregory Szorc [:gps]]

A belated thank you, Kyle! These queries are *very* helpful and I'm already finding some useful data.