Skip to content

test(agent): fix TestAgent_Metadata/Once flake #8613

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 our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 11 commits into from
Jul 20, 2023
Prev Previous commit
Next Next commit
fixup! more debug logging
  • Loading branch information
coadler committed Jul 20, 2023
commit 2ae25c5f9652550d73b15520b3370e10684c2a27
18 changes: 10 additions & 8 deletions agent/agent.go
Original file line number Diff line number Diff line change
Expand Up @@ -242,15 +242,15 @@ func (a *agent) runLoop(ctx context.Context) {
}
}

func (a *agent) collectMetadata(ctx context.Context, md codersdk.WorkspaceAgentMetadataDescription) *codersdk.WorkspaceAgentMetadataResult {
func (a *agent) collectMetadata(ctx context.Context, md codersdk.WorkspaceAgentMetadataDescription, now time.Time) *codersdk.WorkspaceAgentMetadataResult {
var out bytes.Buffer
result := &codersdk.WorkspaceAgentMetadataResult{
// CollectedAt is set here for testing purposes and overrode by
// coderd to the time of server receipt to solve clock skew.
//
// In the future, the server may accept the timestamp from the agent
// if it can guarantee the clocks are synchronized.
CollectedAt: time.Now(),
CollectedAt: now,
}
cmdPty, err := a.sshServer.CreateCommand(ctx, md.Script, nil)
if err != nil {
Expand Down Expand Up @@ -337,9 +337,7 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
case <-ctx.Done():
return
case mr := <-metadataResults:
lastCollectedAtMu.Lock()
lastCollectedAts[mr.key] = mr.result.CollectedAt
lastCollectedAtMu.Unlock()

err := a.client.PostMetadata(ctx, mr.key, *mr.result)
if err != nil {
a.logger.Error(ctx, "agent failed to report metadata", slog.Error(err))
Expand Down Expand Up @@ -406,7 +404,7 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
// If the interval is zero, we assume the user just wants
// a single collection at startup, not a spinning loop.
if md.Interval == 0 {
logger.Debug(ctx, "skipping metadata, interval 0 and alredy collected once")
logger.Debug(ctx, "skipping metadata, interval 0 and already collected once")
return
}
// The last collected value isn't quite stale yet, so we skip it.
Expand Down Expand Up @@ -434,14 +432,18 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
ctx, cancel := context.WithTimeout(ctx, ctxTimeout)
defer cancel()

now := time.Now()
select {
case <-ctx.Done():
logger.Debug(ctx, "metadata collection timed out", slog.F("timeout", ctxTimeout))
case metadataResults <- metadataResultAndKey{
key: md.Key,
result: a.collectMetadata(ctx, md),
result: a.collectMetadata(ctx, md, now),
}:
logger.Debug(ctx, "sent metadata")
logger.Debug(ctx, "sent metadata", slog.F("took", time.Since(now).String()))
lastCollectedAtMu.Lock()
lastCollectedAts[md.Key] = now
lastCollectedAtMu.Unlock()
}
})
}
Expand Down