Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

feat: add provisioning timings to understand slow build times#14274

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to ourterms of service andprivacy statement. We’ll occasionally send you account related emails.

Already on GitHub?Sign in to your account

Merged
dannykopping merged 24 commits intomainfromdk/provision-detailed-apply
Aug 21, 2024

Conversation

dannykopping
Copy link
Contributor

@dannykoppingdannykopping commentedAug 15, 2024•
edited
Loading

This PR productionizes a spike I conducted duringcoder/internal#22.

Terraform exposes discrete timing information for each resource when planning and applying, and we're now using this to build up a view of which resources or stages take the most time. I'm hooking into our existing parsing of the Terraform log lines and expanding it a bit; there were some necessary refactors but I've tried to keep it as low-touch as possible.

This PR doesnot contain any HTTP APIs or UIs. Those will have to be added in subsequent PRs; this one is already fairly large.

There are tests, and they cover the majority of the new code added, but they're incomplete. I had to do some fairly nasty business inprovisioner/terraform/timings_test.go since we don't have a seam in front of calls toos/exec which makes it difficult to mock. There's some precedent for this though inprovisioner/terraform/provision_test.go from which I took heavy inspiration.

We also don't haveany active e2e tests which use terraform, which I think is something worth addressing.

I also includedtxtar after watching Russ Cox'sexcellent talk on Go testing recently, and it made the tests quite readable - at least I think so. If you disagree, let me know.

Using this information, we'll be able to add cool graphs like this to workspace detail pages and probably also expose some aggregated data in Prometheus metrics.

image

johnstcn and stirby reacted with hooray emojijohnstcn reacted with heart emojijohnstcn reacted with rocket emojijohnstcn reacted with eyes emoji
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
…me resource are capturedSigned-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
@alwaysmeticulousalwaysmeticulous
Copy link

alwaysmeticulousbot commentedAug 15, 2024•
edited
Loading

✅ Meticulous spotted zero visual differences across 1408 screens tested:view results.

Meticulous tested none of the executable lines edited in this PR. If this PR does not modify your frontend this is expected. If this is a new feature or Meticulous was recently introduced then Meticulous will generate tests to cover your code in the coming days1.

1. If you wish to increase coverage immediately you can do so by interacting with your feature on localhost.

Expected differences?Click here. Last updated for commit eb5ec5c. This comment will update as new commits are pushed.

Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
@dannykoppingdannykoppingforce-pushed thedk/provision-detailed-apply branch from24477d6 to28fa2f7CompareAugust 15, 2024 13:36
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
@@ -2787,6 +2787,14 @@ func (q *querier) InsertProvisionerJobLogs(ctx context.Context, arg database.Ins
return q.db.InsertProvisionerJobLogs(ctx, arg)
}

// TODO: We need to create a ProvisionerJob resource type
Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

SeeInsertProvisionerJobLogs andInsertProvisionerJob above

@@ -2463,6 +2463,13 @@ func (s *MethodTestSuite) TestSystemFunctions() {
JobID: j.ID,
}).Asserts( /*rbac.ResourceSystem, policy.ActionCreate*/ )
}))
s.Run("InsertProvisionerJobTimings", s.Subtest(func(db database.Store, check *expects) {
// TODO: we need to create a ProvisionerJob resource
Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Ditto.

Comment on lines +23 to +25
pj.worker_id,
pj.error,
pj.error_code,
Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

These are extraneous right now, but when we slap an API on top of this we'll likely need this info and can save ourselves another database call.

Comment on lines +30 to +41
GREATEST(EXTRACT(EPOCH FROM (
MAX(CASE WHEN pjt.stage = 'init'::provisioner_job_timing_stage THEN pjt.ended_at END) -
MIN(CASE WHEN pjt.stage = 'init'::provisioner_job_timing_stage THEN pjt.started_at END))), 0) AS init_secs,
GREATEST(EXTRACT(EPOCH FROM (
MAX(CASE WHEN pjt.stage = 'plan'::provisioner_job_timing_stage THEN pjt.ended_at END) -
MIN(CASE WHEN pjt.stage = 'plan'::provisioner_job_timing_stage THEN pjt.started_at END))), 0) AS plan_secs,
GREATEST(EXTRACT(EPOCH FROM (
MAX(CASE WHEN pjt.stage = 'graph'::provisioner_job_timing_stage THEN pjt.ended_at END) -
MIN(CASE WHEN pjt.stage = 'graph'::provisioner_job_timing_stage THEN pjt.started_at END))), 0) AS graph_secs,
GREATEST(EXTRACT(EPOCH FROM (
MAX(CASE WHEN pjt.stage = 'apply'::provisioner_job_timing_stage THEN pjt.ended_at END) -
MIN(CASE WHEN pjt.stage = 'apply'::provisioner_job_timing_stage THEN pjt.started_at END))), 0) AS apply_secs
Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Use the max(ended_at)-min(started_at) of each stage to determine stage timings.

@@ -539,46 +556,42 @@ func readAndLog(sink logSink, r io.Reader, done chan<- any, level proto.LogLevel
// provisionLogWriter creates a WriteCloser that will log each JSON formatted terraform log. The WriteCloser must be
// closed by the caller to end logging, after which the returned channel will be closed to indicate that logging of the
// written data has finished. Failure to close the WriteCloser will leak a goroutine.
func provisionLogWriter(sink logSink) (io.WriteCloser, <-chan any) {
func(e *executor)provisionLogWriter(sink logSink) (io.WriteCloser, <-chan any) {
Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Moved these under theexecutor receiver to get access to the logger.

@@ -609,12 +676,25 @@ func convertTerraformLogLevel(logLevel string, sink logSink) proto.LogLevel {
}

type terraformProvisionLog struct {
Level string `json:"@level"`
Message string `json:"@message"`
Level string `json:"@level"`
Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

I expanded this type to unmarshal additional fields from the existing JSON logs.

Signed-off-by: Danny Kopping <danny@coder.com>
@dannykoppingdannykopping changed the titleDk/provision detailed applyfeat: add provisioning timings to understand slow build timesAug 15, 2024
Signed-off-by: Danny Kopping <danny@coder.com>
Copy link
Member

@mafredrimafredri left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Nice work, some minor nits and comments but looks good in general 👍🏻

Comment on lines 3 to 4
// protoc-gen-go v1.30.0
// protoc v4.23.3
// protoc-gen-go v1.34.2
// protoc v4.25.3
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

was this intentional?

Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Nope! Good catch.

Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Actually, we don't lock these versions.
In my dogfood workspace running nix, i've got:

$ protoc-gen-go --versionprotoc-gen-go v1.34.2$ protoc --versionlibprotoc 25.3$ which protoc protoc-gen-go/nix/var/nix/profiles/default/bin/protoc/nix/var/nix/profiles/default/bin/protoc-gen-go

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

I think CI uses the 'regular' dogfood image as opposed to 'nix'. This probably isn't a huge issue tbh but just wanted to double-check.

Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

I would beg to differ.

If our dev environments' and our CI environment's dependencies are not in lock-step, this could lead not only to CI frustrations like the one above but to something more pernicious. We're either getting false-positives or false-negatives: any alignment is temporary/incidental, and we have no source of truth.

Copy link
ContributorAuthor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

Added#14343 as a follow-up.

@dannykoppingdannykopping marked this pull request as ready for reviewAugust 15, 2024 18:22
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
@dannykoppingdannykoppingforce-pushed thedk/provision-detailed-apply branch fromb5218be to597ec85CompareAugust 19, 2024 10:24
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Signed-off-by: Danny Kopping <danny@coder.com>
Copy link
Member

@johnstcnjohnstcn left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others.Learn more.

I don't have any blocking changes here, but it would be good to verify the situation with external provisioners on upgrade.

@dannykoppingdannykopping merged commit6960d19 intomainAug 21, 2024
34 checks passed
@dannykoppingdannykopping deleted the dk/provision-detailed-apply branchAugust 21, 2024 12:19
@github-actionsgithub-actionsbot locked and limited conversation to collaboratorsAug 21, 2024
@matifalimatifali added the roadmaphttps://coder.com/roadmap. Only humans may set this. labelOct 22, 2024
@codercoder unlocked this conversationNov 14, 2024
@codercoder locked asresolvedand limited conversation to collaboratorsNov 14, 2024
Sign up for freeto subscribe to this conversation on GitHub. Already have an account?Sign in.
Reviewers

@mafredrimafredrimafredri left review comments

@johnstcnjohnstcnjohnstcn approved these changes

@spikecurtisspikecurtisAwaiting requested review from spikecurtisspikecurtis is a code owner

Assignees

@dannykoppingdannykopping

Labels
roadmaphttps://coder.com/roadmap. Only humans may set this.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

4 participants
@dannykopping@mafredri@johnstcn@matifali
[8]ページ先頭
©2009-2025 Movatter.jp