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

fix(coderd): ensure agent timings are non-zero on insert#18065

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
johnstcn merged 7 commits intomainfromcj/no-zero-timings
May 29, 2025
Merged
Show file tree
Hide file tree
Changes fromall commits
Commits
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
6 changes: 6 additions & 0 deletionsagent/agentscripts/agentscripts_test.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -144,6 +144,12 @@ func TestScriptReportsTiming(t *testing.T) {

timing := timings[0]
require.Equal(t, int32(0), timing.ExitCode)
if assert.True(t, timing.Start.IsValid(), "start time should be valid") {
require.NotZero(t, timing.Start.AsTime(), "start time should not be zero")
}
if assert.True(t, timing.End.IsValid(), "end time should be valid") {
require.NotZero(t, timing.End.AsTime(), "end time should not be zero")
}
require.GreaterOrEqual(t, timing.End.AsTime(), timing.Start.AsTime())
}

Expand Down
20 changes: 19 additions & 1 deletioncoderd/agentapi/scripts.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -18,11 +18,29 @@ type ScriptsAPI struct {
func (s *ScriptsAPI) ScriptCompleted(ctx context.Context, req *agentproto.WorkspaceAgentScriptCompletedRequest) (*agentproto.WorkspaceAgentScriptCompletedResponse, error) {
res := &agentproto.WorkspaceAgentScriptCompletedResponse{}

scriptID, err := uuid.FromBytes(req.Timing.ScriptId)
if req.GetTiming() == nil {
return nil, xerrors.New("script timing is required")
}

scriptID, err := uuid.FromBytes(req.GetTiming().GetScriptId())
if err != nil {
return nil, xerrors.Errorf("script id from bytes: %w", err)
}

scriptStart := req.GetTiming().GetStart()
if !scriptStart.IsValid() || scriptStart.AsTime().IsZero() {
return nil, xerrors.New("script start time is required and cannot be zero")
}

scriptEnd := req.GetTiming().GetEnd()
if !scriptEnd.IsValid() || scriptEnd.AsTime().IsZero() {
return nil, xerrors.New("script end time is required and cannot be zero")
}

if scriptStart.AsTime().After(scriptEnd.AsTime()) {
return nil, xerrors.New("script start time cannot be after end time")
}

var stage database.WorkspaceAgentScriptTimingStage
switch req.Timing.Stage {
case agentproto.Timing_START:
Expand Down
97 changes: 86 additions & 11 deletionscoderd/agentapi/scripts_test.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -6,6 +6,7 @@ import (
"time"

"github.com/google/uuid"
"github.com/stretchr/testify/require"
"go.uber.org/mock/gomock"
"google.golang.org/protobuf/types/known/timestamppb"

Expand All@@ -20,8 +21,10 @@ func TestScriptCompleted(t *testing.T) {
t.Parallel()

tests := []struct {
scriptID uuid.UUID
timing *agentproto.Timing
scriptID uuid.UUID
timing *agentproto.Timing
expectInsert bool
expectError string
}{
{
scriptID: uuid.New(),
Expand All@@ -32,6 +35,7 @@ func TestScriptCompleted(t *testing.T) {
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: true,
},
{
scriptID: uuid.New(),
Expand All@@ -42,6 +46,7 @@ func TestScriptCompleted(t *testing.T) {
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: true,
},
{
scriptID: uuid.New(),
Expand All@@ -52,6 +57,7 @@ func TestScriptCompleted(t *testing.T) {
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: true,
},
{
scriptID: uuid.New(),
Expand All@@ -62,6 +68,7 @@ func TestScriptCompleted(t *testing.T) {
Status: agentproto.Timing_TIMED_OUT,
ExitCode: 255,
},
expectInsert: true,
},
{
scriptID: uuid.New(),
Expand All@@ -72,6 +79,67 @@ func TestScriptCompleted(t *testing.T) {
Status: agentproto.Timing_EXIT_FAILURE,
ExitCode: 1,
},
expectInsert: true,
},
{
scriptID: uuid.New(),
timing: &agentproto.Timing{
Stage: agentproto.Timing_START,
Start: nil,
End: timestamppb.New(dbtime.Now().Add(time.Second)),
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: false,
expectError: "script start time is required and cannot be zero",
},
{
scriptID: uuid.New(),
timing: &agentproto.Timing{
Stage: agentproto.Timing_START,
Start: timestamppb.New(dbtime.Now()),
End: nil,
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: false,
expectError: "script end time is required and cannot be zero",
},
{
scriptID: uuid.New(),
timing: &agentproto.Timing{
Stage: agentproto.Timing_START,
Start: timestamppb.New(time.Time{}),
End: timestamppb.New(dbtime.Now()),
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: false,
expectError: "script start time is required and cannot be zero",
},
{
scriptID: uuid.New(),
timing: &agentproto.Timing{
Stage: agentproto.Timing_START,
Start: timestamppb.New(dbtime.Now()),
End: timestamppb.New(time.Time{}),
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: false,
expectError: "script end time is required and cannot be zero",
},
{
scriptID: uuid.New(),
timing: &agentproto.Timing{
Stage: agentproto.Timing_START,
Start: timestamppb.New(dbtime.Now()),
End: timestamppb.New(dbtime.Now().Add(-time.Second)),
Status: agentproto.Timing_OK,
ExitCode: 0,
},
expectInsert: false,
expectError: "script start time cannot be after end time",
},
}

Expand All@@ -80,19 +148,26 @@ func TestScriptCompleted(t *testing.T) {
tt.timing.ScriptId = tt.scriptID[:]

mDB := dbmock.NewMockStore(gomock.NewController(t))
mDB.EXPECT().InsertWorkspaceAgentScriptTimings(gomock.Any(), database.InsertWorkspaceAgentScriptTimingsParams{
ScriptID: tt.scriptID,
Stage: protoScriptTimingStageToDatabase(tt.timing.Stage),
Status: protoScriptTimingStatusToDatabase(tt.timing.Status),
StartedAt: tt.timing.Start.AsTime(),
EndedAt: tt.timing.End.AsTime(),
ExitCode: tt.timing.ExitCode,
})
if tt.expectInsert {
mDB.EXPECT().InsertWorkspaceAgentScriptTimings(gomock.Any(), database.InsertWorkspaceAgentScriptTimingsParams{
ScriptID: tt.scriptID,
Stage: protoScriptTimingStageToDatabase(tt.timing.Stage),
Status: protoScriptTimingStatusToDatabase(tt.timing.Status),
StartedAt: tt.timing.Start.AsTime(),
EndedAt: tt.timing.End.AsTime(),
ExitCode: tt.timing.ExitCode,
})
}

api := &agentapi.ScriptsAPI{Database: mDB}
api.ScriptCompleted(context.Background(), &agentproto.WorkspaceAgentScriptCompletedRequest{
_, err :=api.ScriptCompleted(context.Background(), &agentproto.WorkspaceAgentScriptCompletedRequest{
Timing: tt.timing,
})
if tt.expectError != "" {
require.Contains(t, err.Error(), tt.expectError, "expected error did not match")
} else {
require.NoError(t, err, "expected no error but got one")
}
}
}

Expand Down
11 changes: 11 additions & 0 deletionscoderd/database/dbgen/dbgen.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -215,6 +215,17 @@ func WorkspaceAgent(t testing.TB, db database.Store, orig database.WorkspaceAgen
APIKeyScope: takeFirst(orig.APIKeyScope, database.AgentKeyScopeEnumAll),
})
require.NoError(t, err, "insert workspace agent")
if orig.FirstConnectedAt.Valid || orig.LastConnectedAt.Valid || orig.DisconnectedAt.Valid || orig.LastConnectedReplicaID.Valid {
err = db.UpdateWorkspaceAgentConnectionByID(genCtx, database.UpdateWorkspaceAgentConnectionByIDParams{
ID: agt.ID,
FirstConnectedAt: takeFirst(orig.FirstConnectedAt, agt.FirstConnectedAt),
LastConnectedAt: takeFirst(orig.LastConnectedAt, agt.LastConnectedAt),
DisconnectedAt: takeFirst(orig.DisconnectedAt, agt.DisconnectedAt),
LastConnectedReplicaID: takeFirst(orig.LastConnectedReplicaID, agt.LastConnectedReplicaID),
UpdatedAt: takeFirst(orig.UpdatedAt, agt.UpdatedAt),
})
require.NoError(t, err, "update workspace agent first connected at")
}
return agt
}

Expand Down
13 changes: 10 additions & 3 deletionscoderd/provisionerdserver/provisionerdserver.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -1741,8 +1741,15 @@ func (s *server) completeWorkspaceBuildJob(ctx context.Context, job database.Pro
JobID: jobID,
}
for _, t := range jobType.WorkspaceBuild.Timings {
if t.Start == nil || t.End == nil {
s.Logger.Warn(ctx, "timings entry has nil start or end time", slog.F("entry", t.String()))
start := t.GetStart()
if !start.IsValid() || start.AsTime().IsZero() {
s.Logger.Warn(ctx, "timings entry has nil or zero start time", slog.F("job_id", job.ID.String()), slog.F("workspace_id", workspace.ID), slog.F("workspace_build_id", workspaceBuild.ID), slog.F("user_id", workspace.OwnerID))
continue
}

end := t.GetEnd()
if !end.IsValid() || end.AsTime().IsZero() {
s.Logger.Warn(ctx, "timings entry has nil or zero end time, skipping", slog.F("job_id", job.ID.String()), slog.F("workspace_id", workspace.ID), slog.F("workspace_build_id", workspaceBuild.ID), slog.F("user_id", workspace.OwnerID))
continue
}

Expand DownExpand Up@@ -1771,7 +1778,7 @@ func (s *server) completeWorkspaceBuildJob(ctx context.Context, job database.Pro
// after being started.
//
// Agent timeouts could be minutes apart, resulting in an unresponsive
// experience, so we'll notify after every unique timeout seconds.
// experience, so we'll notify after every unique timeout seconds
if !input.DryRun && workspaceBuild.Transition == database.WorkspaceTransitionStart && len(agentTimeouts) > 0 {
timeouts := maps.Keys(agentTimeouts)
slices.Sort(timeouts)
Expand Down
59 changes: 51 additions & 8 deletionscoderd/provisionerdserver/provisionerdserver_test.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -1301,14 +1301,57 @@ func TestCompleteJob(t *testing.T) {
Name: "test-workspace-resource",
Type: "aws_instance",
}},
Timings: []*sdkproto.Timing{{
Stage: "test",
Source: "test-source",
Resource: "test-resource",
Action: "test-action",
Start: timestamppb.Now(),
End: timestamppb.Now(),
}},
Timings: []*sdkproto.Timing{
{
Stage: "test",
Source: "test-source",
Resource: "test-resource",
Action: "test-action",
Start: timestamppb.Now(),
End: timestamppb.Now(),
},
{
Stage: "test2",
Source: "test-source2",
Resource: "test-resource2",
Action: "test-action2",
// Start: omitted
// End: omitted
},
{
Stage: "test3",
Source: "test-source3",
Resource: "test-resource3",
Action: "test-action3",
Start: timestamppb.Now(),
End: nil,
},
{
Stage: "test3",
Source: "test-source3",
Resource: "test-resource3",
Action: "test-action3",
Start: nil,
End: timestamppb.Now(),
},
{
Stage: "test4",
Source: "test-source4",
Resource: "test-resource4",
Action: "test-action4",
Start: timestamppb.New(time.Time{}),
End: timestamppb.Now(),
},
{
Stage: "test5",
Source: "test-source5",
Resource: "test-resource5",
Action: "test-action5",
Start: timestamppb.Now(),
End: timestamppb.New(time.Time{}),
},
nil, // nil timing should be ignored
},
},
},
})
Expand Down
29 changes: 29 additions & 0 deletionscoderd/workspacebuilds.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -1176,6 +1176,16 @@ func (api *API) buildTimings(ctx context.Context, build database.WorkspaceBuild)
}

for _, t := range provisionerTimings {
// Ref: #15432: agent script timings must not have a zero start or end time.
if t.StartedAt.IsZero() || t.EndedAt.IsZero() {
api.Logger.Debug(ctx, "ignoring provisioner timing with zero start or end time",
slog.F("workspace_id", build.WorkspaceID),
slog.F("workspace_build_id", build.ID),
slog.F("provisioner_job_id", t.JobID),
)
continue
}

res.ProvisionerTimings = append(res.ProvisionerTimings, codersdk.ProvisionerTiming{
JobID: t.JobID,
Stage: codersdk.TimingStage(t.Stage),
Expand All@@ -1187,6 +1197,17 @@ func (api *API) buildTimings(ctx context.Context, build database.WorkspaceBuild)
})
}
for _, t := range agentScriptTimings {
// Ref: #15432: agent script timings must not have a zero start or end time.
if t.StartedAt.IsZero() || t.EndedAt.IsZero() {
api.Logger.Debug(ctx, "ignoring agent script timing with zero start or end time",
slog.F("workspace_id", build.WorkspaceID),
slog.F("workspace_agent_id", t.WorkspaceAgentID),
slog.F("workspace_build_id", build.ID),
slog.F("workspace_agent_script_id", t.ScriptID),
)
continue
}

Copy link
Member

@mafredrimafredriMay 28, 2025•
edited
Loading

Choose a reason for hiding this comment

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

The issue referenced in#15432 originates from thecodersdk.TimingStageConnect timing that's further down, but that one doesn't seem addressed?

Theagent.FirstConnectedAt.Time is used unconditionally, but may be null. Do we have a way to represent this better?

We could always omit the entry, but personally I'd like to see it in the graph as an unterminated starting point, would give an indication we're waiting for something.

Copy link
MemberAuthor

Choose a reason for hiding this comment

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

We could represent both of these ascodersdk.NullTime instead.

Copy link
MemberAuthor

Choose a reason for hiding this comment

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

It turns out the timings chart is built to render with a "loading" state until all of provisioner timings, script timings, and connection timings are populated with at least one value. The assumption here is that timings are only useful after a build has completed.

My previous change (#18058) adds a check in the UI so that causes a time range with a zero time to be rendered as an "instant" with an "Invalid" label.

I think that, for now, it makes sense to simply exclude the agent connection timing if!FirstConnectedAt.Valid. Does that sound alright?

Copy link
Member

Choose a reason for hiding this comment

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

I'm fine with that if it can show up later if the agent finally connects 👍🏻

res.AgentScriptTimings = append(res.AgentScriptTimings, codersdk.AgentScriptTiming{
StartedAt: t.StartedAt,
EndedAt: t.EndedAt,
Expand All@@ -1199,6 +1220,14 @@ func (api *API) buildTimings(ctx context.Context, build database.WorkspaceBuild)
})
}
for _, agent := range agents {
if agent.FirstConnectedAt.Time.IsZero() {
api.Logger.Debug(ctx, "ignoring agent connection timing with zero first connected time",
slog.F("workspace_id", build.WorkspaceID),
slog.F("workspace_agent_id", agent.ID),
slog.F("workspace_build_id", build.ID),
)
continue
}
res.AgentConnectionTimings = append(res.AgentConnectionTimings, codersdk.AgentConnectionTiming{
WorkspaceAgentID: agent.ID.String(),
WorkspaceAgentName: agent.Name,
Expand Down
7 changes: 5 additions & 2 deletionscoderd/workspacebuilds_test.go
View file
Open in desktop
Original file line numberDiff line numberDiff line change
Expand Up@@ -2,6 +2,7 @@ package coderd_test

import (
"context"
"database/sql"
"errors"
"fmt"
"net/http"
Expand DownExpand Up@@ -1736,7 +1737,8 @@ func TestWorkspaceBuildTimings(t *testing.T) {
JobID: build.JobID,
})
agent := dbgen.WorkspaceAgent(t, db, database.WorkspaceAgent{
ResourceID: resource.ID,
ResourceID: resource.ID,
FirstConnectedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-time.Hour)},
})

// When: fetching timings for the build
Expand DownExpand Up@@ -1767,7 +1769,8 @@ func TestWorkspaceBuildTimings(t *testing.T) {
agents := make([]database.WorkspaceAgent, 5)
for i := range agents {
agents[i] = dbgen.WorkspaceAgent(t, db, database.WorkspaceAgent{
ResourceID: resource.ID,
ResourceID: resource.ID,
FirstConnectedAt: sql.NullTime{Valid: true, Time: dbtime.Now().Add(-time.Duration(i) * time.Hour)},
})
}

Expand Down
Loading
[8]ページ先頭
©2009-2025 Movatter.jp