Skip to content
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