Skip to content

Commit a070e07

Browse files
dannykoppingdannykopping
committed
Expand hash to include span category so multiple operations on the same resource are captured
Signed-off-by: Danny Kopping <danny@coder.com>
1 parent 973ec6d commit a070e07

File tree

3 files changed

+68
-43
lines changed

3 files changed

+68
-43
lines changed

‎provisioner/terraform/executor.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -272,15 +272,15 @@ func (e *executor) plan(ctx, killCtx context.Context, env, vars []string, logr l
272272

273273
// Capture the duration of the call to `terraform graph`.
274274
graphTimings := newTimingAggregator(database.ProvisionerJobTimingStageGraph)
275-
graphTimings.ingest(createGraphTimingsEvent(graphStart))
275+
graphTimings.ingest(createGraphTimingsEvent(timingGraphStart))
276276

277277
state, err := e.planResources(ctx, killCtx, planfilePath)
278278
if err != nil {
279-
graphTimings.ingest(createGraphTimingsEvent(graphErrored))
279+
graphTimings.ingest(createGraphTimingsEvent(timingGraphErrored))
280280
return nil, err
281281
}
282282

283-
graphTimings.ingest(createGraphTimingsEvent(graphComplete))
283+
graphTimings.ingest(createGraphTimingsEvent(timingGraphComplete))
284284

285285
return &proto.PlanComplete{
286286
Parameters: state.Parameters,

‎provisioner/terraform/provision.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -106,17 +106,17 @@ func (s *server) Plan(
106106
// The JSON output of `terraform init` doesn't include discrete fields for capturing timings of each plugin,
107107
// so we capture the whole init process.
108108
initTimings := newTimingAggregator(database.ProvisionerJobTimingStageInit)
109-
initTimings.ingest(createInitTimingsEvent(initStart))
109+
initTimings.ingest(createInitTimingsEvent(timingInitStart))
110110

111111
err = e.init(ctx, killCtx, sess)
112112
if err != nil {
113-
initTimings.ingest(createInitTimingsEvent(initErrored))
113+
initTimings.ingest(createInitTimingsEvent(timingInitErrored))
114114

115115
s.logger.Debug(ctx, "init failed", slog.Error(err))
116116
return provisionersdk.PlanErrorf("initialize terraform: %s", err)
117117
}
118118

119-
initTimings.ingest(createInitTimingsEvent(initComplete))
119+
initTimings.ingest(createInitTimingsEvent(timingInitComplete))
120120

121121
s.logger.Debug(ctx, "ran initialization")
122122

‎provisioner/terraform/timings.go

Lines changed: 62 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -19,23 +19,23 @@ type timingKind string
1919
// Copied from https://github.com/hashicorp/terraform/blob/ffbcaf8bef12bb1f4d79f06437f414e280d08761/internal/command/views/json/message_types.go
2020
// We cannot reference these because they're in an internal package.
2121
const (
22-
applyStart timingKind = "apply_start"
23-
applyProgress timingKind = "apply_progress"
24-
applyComplete timingKind = "apply_complete"
25-
applyErrored timingKind = "apply_errored"
26-
provisionStart timingKind = "provision_start"
27-
provisionProgress timingKind = "provision_progress"
28-
provisionComplete timingKind = "provision_complete"
29-
provisionErrored timingKind = "provision_errored"
30-
refreshStart timingKind = "refresh_start"
31-
refreshComplete timingKind = "refresh_complete"
22+
timingApplyStart timingKind = "apply_start"
23+
timingApplyProgress timingKind = "apply_progress"
24+
timingApplyComplete timingKind = "apply_complete"
25+
timingApplyErrored timingKind = "apply_errored"
26+
timingProvisionStart timingKind = "provision_start"
27+
timingProvisionProgress timingKind = "provision_progress"
28+
timingProvisionComplete timingKind = "provision_complete"
29+
timingProvisionErrored timingKind = "provision_errored"
30+
timingRefreshStart timingKind = "refresh_start"
31+
timingRefreshComplete timingKind = "refresh_complete"
3232
// These are not part of message_types, but we want to track init/graph timings as well.
33-
initStart timingKind = "init_start"
34-
initComplete timingKind = "init_complete"
35-
initErrored timingKind = "init_errored"
36-
graphStart timingKind = "graph_start"
37-
graphComplete timingKind = "graph_complete"
38-
graphErrored timingKind = "graph_errored"
33+
timingInitStart timingKind = "init_start"
34+
timingInitComplete timingKind = "init_complete"
35+
timingInitErrored timingKind = "init_errored"
36+
timingGraphStart timingKind = "graph_start"
37+
timingGraphComplete timingKind = "graph_complete"
38+
timingGraphErrored timingKind = "graph_errored"
3939
)
4040

4141
type timingAggregator struct {
@@ -74,13 +74,13 @@ func (t *timingAggregator) ingest(ts time.Time, s *timingSpan) {
7474
ts = dbtime.Time(ts)
7575

7676
switch s.kind {
77-
case applyStart, provisionStart, refreshStart, initStart, graphStart:
77+
case timingApplyStart, timingProvisionStart, timingRefreshStart, timingInitStart, timingGraphStart:
7878
s.start = ts
7979
s.state = proto.TimingState_STARTED
80-
case applyComplete, provisionComplete, refreshComplete, initComplete, graphComplete:
80+
case timingApplyComplete, timingProvisionComplete, timingRefreshComplete, timingInitComplete, timingGraphComplete:
8181
s.end = ts
8282
s.state = proto.TimingState_COMPLETED
83-
case applyErrored, provisionErrored, initErrored, graphErrored:
83+
case timingApplyErrored, timingProvisionErrored, timingInitErrored, timingGraphErrored:
8484
s.end = ts
8585
s.state = proto.TimingState_FAILED
8686
default:
@@ -137,33 +137,58 @@ func (t *timingAggregator) aggregate() []*proto.Timing {
137137

138138
func (l timingKind) Valid() bool {
139139
return slices.Contains([]timingKind{
140-
applyStart,
141-
applyProgress,
142-
applyComplete,
143-
applyErrored,
144-
provisionStart,
145-
provisionProgress,
146-
provisionComplete,
147-
provisionErrored,
148-
refreshStart,
149-
refreshComplete,
150-
initStart,
151-
initComplete,
152-
initErrored,
153-
graphStart,
154-
graphComplete,
155-
graphErrored,
140+
timingApplyStart,
141+
timingApplyProgress,
142+
timingApplyComplete,
143+
timingApplyErrored,
144+
timingProvisionStart,
145+
timingProvisionProgress,
146+
timingProvisionComplete,
147+
timingProvisionErrored,
148+
timingRefreshStart,
149+
timingRefreshComplete,
150+
timingInitStart,
151+
timingInitComplete,
152+
timingInitErrored,
153+
timingGraphStart,
154+
timingGraphComplete,
155+
timingGraphErrored,
156156
}, l)
157157
}
158158

159+
// Category returns the category for a giving timing state so that timings can be aggregated by this category.
160+
// We can't use the state itself because we need an `apply_start` and an `apply_complete` to both hash to the same entry
161+
// if all other attributes are identical.
162+
func (l timingKind) Category() string {
163+
switch l {
164+
case timingInitStart, timingInitComplete, timingInitErrored:
165+
return "init"
166+
case timingGraphStart, timingGraphComplete, timingGraphErrored:
167+
return "graph"
168+
case timingApplyStart, timingApplyProgress, timingApplyComplete, timingApplyErrored:
169+
return "apply"
170+
case timingProvisionStart, timingProvisionProgress, timingProvisionComplete, timingProvisionErrored:
171+
return "provision"
172+
case timingRefreshStart, timingRefreshComplete:
173+
return "state refresh"
174+
default:
175+
return "?"
176+
}
177+
}
178+
159179
// hashState computes a hash based on a timingSpan's unique properties and state.
160180
// The combination of resource and provider names MUST be unique across entries.
161181
func (e *timingSpan) hashByState(state proto.TimingState) uint64 {
162-
id := fmt.Sprintf("%s:%s:%s", state.String(), e.resource, e.provider)
182+
id := fmt.Sprintf("%s:%s:%s:%s", e.kind.Category(), state.String(), e.resource, e.provider)
163183
return xxhash.Sum64String(id)
164184
}
165185

166186
func (e *timingSpan) toProto() *proto.Timing {
187+
// Some log entries, like state refreshes, don't have any "action" logged.
188+
if e.action == "" {
189+
e.action = e.kind.Category()
190+
}
191+
167192
return &proto.Timing{
168193
Start: timestamppb.New(e.start),
169194
End: timestamppb.New(e.end),
@@ -191,4 +216,4 @@ func createGraphTimingsEvent(event timingKind) (time.Time, *timingSpan) {
191216
provider: "terraform",
192217
resource: "state file",
193218
}
194-
}
219+
}

0 commit comments

Comments
 (0)