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.

Sign up for GitHub

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
Merged

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

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
3b0b1f3
flake(agent) fix `TestAgent_Metadata/Once` flake
coadler Jul 19, 2023
cf2f7dc
fixup! flake(agent) fix `TestAgent_Metadata/Once` flake
coadler Jul 19, 2023
3f73d16
fixup! flake(agent) fix `TestAgent_Metadata/Once` flake
coadler Jul 20, 2023
7b4097a
fixup! flake(agent) fix `TestAgent_Metadata/Once` flake
coadler Jul 20, 2023
76b3bb8
more debug logging
coadler Jul 20, 2023
4b08319
fixup! more debug logging
coadler Jul 20, 2023
2ae25c5
fixup! more debug logging
coadler Jul 20, 2023
07a5b9a
fixup! more debug logging
coadler Jul 20, 2023
d195640
fixup! more debug logging
coadler Jul 20, 2023
14eb5a7
fixup! more debug logging
coadler Jul 20, 2023
b55e04b
fixup! more debug logging
coadler Jul 20, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
more debug logging
  • Loading branch information
@coadler
coadler committed Jul 20, 2023
commit 76b3bb8c9819ac096d157314004e3ab1a6f0473b
23 changes: 18 additions & 5 deletions agent/agent.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -320,6 +320,7 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
lastCollectedAtMu sync.RWMutex
lastCollectedAts = make(map[string]time.Time)
metadataResults = make(chan metadataResultAndKey, metadataLimit)
logger = a.logger.Named("metadata")
)
defer baseTicker.Stop()

Expand All @@ -330,6 +331,8 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
var flight trySingleflight

for {
var delay time.Duration

select {
case <-ctx.Done():
return
Expand All @@ -340,14 +343,16 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
a.logger.Error(ctx, "agent failed to report metadata", slog.Error(err))
}
continue
case <-baseTicker.C:
case t := <-baseTicker.C:
delay = time.Since(t)
}

logger.Debug(ctx, "report metadata ticking", slog.F("delay", delay.String()))

if len(metadataResults) > 0 {
// The inner collection loop expects the channel is empty before spinning up
// all the collection goroutines.
a.logger.Debug(
ctx, "metadata collection backpressured",
logger.Debug(ctx, "metadata collection backpressured",
slog.F("queue_len", len(metadataResults)),
)
continue
Expand All @@ -359,7 +364,7 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
}

if len(manifest.Metadata) > metadataLimit {
a.logger.Error(
logger.Error(
ctx, "metadata limit exceeded",
slog.F("limit", metadataLimit), slog.F("got", len(manifest.Metadata)),
)
Expand All @@ -374,6 +379,9 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
if slices.IndexFunc(manifest.Metadata, func(md codersdk.WorkspaceAgentMetadataDescription) bool {
return md.Key == key
}) < 0 {
logger.Debug(ctx, "deleting lastCollected key, missing from manifest",
slog.F("key", key),
)
delete(lastCollectedAts, key)
}
}
Expand All @@ -388,17 +396,20 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
// sending the same result multiple times. So, we don't care about
// the return values.
go flight.Do(md.Key, func() {
ctx := slog.With(ctx, slog.F("key", md.Key))
lastCollectedAtMu.RLock()
collectedAt, ok := lastCollectedAts[md.Key]
lastCollectedAtMu.RUnlock()
if ok {
// 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")
return
}
// The last collected value isn't quite stale yet, so we skip it.
if collectedAt.Add(a.reportMetadataInterval).After(time.Now()) {
logger.Debug(ctx, "skipping metadata, ")
return
}
}
Expand All @@ -417,11 +428,13 @@ func (a *agent) reportMetadataLoop(ctx context.Context) {
timeout = 5
}
}
ctx, cancel := context.WithTimeout(ctx, time.Duration(timeout)*time.Second)
ctxTimeout := time.Duration(timeout) * time.Second
ctx, cancel := context.WithTimeout(ctx, ctxTimeout)
defer cancel()

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),
Expand Down
2 changes: 1 addition & 1 deletion agent/agent_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1905,7 +1905,7 @@ func setupAgent(t *testing.T, metadata agentsdk.Manifest, ptyTimeout time.Durati
})
statsCh := make(chan *agentsdk.Stats, 50)
fs := afero.NewMemMapFs()
c := agenttest.NewClient(t, logger, metadata.AgentID, metadata, statsCh, coordinator)
c := agenttest.NewClient(t, logger.Named("agent"), metadata.AgentID, metadata, statsCh, coordinator)

options := agent.Options{
Client: c,
Expand Down