diff --git a/agent/agent.go b/agent/agent.go index 0aaec4effa..b86db9a4ff 100644 --- a/agent/agent.go +++ b/agent/agent.go @@ -332,7 +332,7 @@ func (a *agent) reportMetadataLoop(ctx context.Context) { lastCollectedAts[mr.key] = mr.result.CollectedAt err := a.client.PostMetadata(ctx, mr.key, *mr.result) if err != nil { - a.logger.Error(ctx, "report metadata", slog.Error(err)) + a.logger.Error(ctx, "agent failed to report metadata", slog.Error(err)) } case <-baseTicker.C: } @@ -462,7 +462,7 @@ func (a *agent) reportLifecycleLoop(ctx context.Context) { return } // If we fail to report the state we probably shouldn't exit, log only. - a.logger.Error(ctx, "post state", slog.Error(err)) + a.logger.Error(ctx, "agent failed to report the lifecycle state", slog.Error(err)) } } } @@ -1365,7 +1365,7 @@ func (a *agent) startReportingConnectionStats(ctx context.Context) { ) }) if err != nil { - a.logger.Error(ctx, "report stats", slog.Error(err)) + a.logger.Error(ctx, "agent failed to report stats", slog.Error(err)) } else { if err = a.trackConnGoroutine(func() { // This is OK because the agent never re-creates the tailnet diff --git a/agent/agentssh/agentssh.go b/agent/agentssh/agentssh.go index 3d4ac69c47..3cf7bec3b0 100644 --- a/agent/agentssh/agentssh.go +++ b/agent/agentssh/agentssh.go @@ -341,7 +341,7 @@ func (s *Server) startPTYSession(session ptySession, magicTypeLabel string, cmd if manifest != nil { err := showMOTD(session, manifest.MOTDFile) if err != nil { - s.logger.Error(ctx, "show MOTD", slog.Error(err)) + s.logger.Error(ctx, "agent failed to show MOTD", slog.Error(err)) s.metrics.sessionErrors.WithLabelValues(magicTypeLabel, "yes", "motd").Add(1) } } else { @@ -410,7 +410,7 @@ func (s *Server) startPTYSession(session ptySession, magicTypeLabel string, cmd // ExitErrors just mean the command we run returned a non-zero exit code, which is normal // and not something to be concerned about. But, if it's something else, we should log it. if err != nil && !xerrors.As(err, &exitErr) { - s.logger.Warn(ctx, "wait error", slog.Error(err)) + s.logger.Warn(ctx, "process wait exited with error", slog.Error(err)) s.metrics.sessionErrors.WithLabelValues(magicTypeLabel, "yes", "wait").Add(1) } if err != nil { diff --git a/coderd/audit.go b/coderd/audit.go index 5a2c41b3e5..d36439a3b7 100644 --- a/coderd/audit.go +++ b/coderd/audit.go @@ -284,7 +284,7 @@ func (api *API) auditLogIsResourceDeleted(ctx context.Context, alog database.Get if xerrors.Is(err, sql.ErrNoRows) { return true } - api.Logger.Error(ctx, "fetch template", slog.Error(err)) + api.Logger.Error(ctx, "unable to fetch template", slog.Error(err)) } return template.Deleted case database.ResourceTypeUser: @@ -293,7 +293,7 @@ func (api *API) auditLogIsResourceDeleted(ctx context.Context, alog database.Get if xerrors.Is(err, sql.ErrNoRows) { return true } - api.Logger.Error(ctx, "fetch user", slog.Error(err)) + api.Logger.Error(ctx, "unable to fetch user", slog.Error(err)) } return user.Deleted case database.ResourceTypeWorkspace: @@ -302,7 +302,7 @@ func (api *API) auditLogIsResourceDeleted(ctx context.Context, alog database.Get if xerrors.Is(err, sql.ErrNoRows) { return true } - api.Logger.Error(ctx, "fetch workspace", slog.Error(err)) + api.Logger.Error(ctx, "unable to fetch workspace", slog.Error(err)) } return workspace.Deleted case database.ResourceTypeWorkspaceBuild: @@ -311,7 +311,7 @@ func (api *API) auditLogIsResourceDeleted(ctx context.Context, alog database.Get if xerrors.Is(err, sql.ErrNoRows) { return true } - api.Logger.Error(ctx, "fetch workspace build", slog.Error(err)) + api.Logger.Error(ctx, "unable to fetch workspace build", slog.Error(err)) } // We use workspace as a proxy for workspace build here workspace, err := api.Database.GetWorkspaceByID(ctx, workspaceBuild.WorkspaceID) @@ -319,7 +319,7 @@ func (api *API) auditLogIsResourceDeleted(ctx context.Context, alog database.Get if xerrors.Is(err, sql.ErrNoRows) { return true } - api.Logger.Error(ctx, "fetch workspace", slog.Error(err)) + api.Logger.Error(ctx, "unable to fetch workspace", slog.Error(err)) } return workspace.Deleted default: diff --git a/coderd/authorize.go b/coderd/authorize.go index 585450c972..229c7e4624 100644 --- a/coderd/authorize.go +++ b/coderd/authorize.go @@ -22,7 +22,7 @@ func AuthorizeFilter[O rbac.Objecter](h *HTTPAuthorizer, r *http.Request, action objects, err := rbac.Filter(r.Context(), h.Authorizer, roles.Actor, action, objects) if err != nil { // Log the error as Filter should not be erroring. - h.Logger.Error(r.Context(), "filter failed", + h.Logger.Error(r.Context(), "authorization filter failed", slog.Error(err), slog.F("user_id", roles.Actor.ID), slog.F("username", roles.ActorName), diff --git a/coderd/csp.go b/coderd/csp.go index 8a47f1009c..ba87adfc63 100644 --- a/coderd/csp.go +++ b/coderd/csp.go @@ -31,7 +31,7 @@ func (api *API) logReportCSPViolations(rw http.ResponseWriter, r *http.Request) dec := json.NewDecoder(r.Body) err := dec.Decode(&v) if err != nil { - api.Logger.Warn(ctx, "csp violation", slog.Error(err)) + api.Logger.Warn(ctx, "CSP violation reported", slog.Error(err)) httpapi.Write(ctx, rw, http.StatusBadRequest, codersdk.Response{ Message: "Failed to read body, invalid json.", Detail: err.Error(), @@ -43,7 +43,7 @@ func (api *API) logReportCSPViolations(rw http.ResponseWriter, r *http.Request) for k, v := range v.Report { fields = append(fields, slog.F(k, v)) } - api.Logger.Debug(ctx, "csp violation", fields...) + api.Logger.Debug(ctx, "CSP violation reported", fields...) httpapi.Write(ctx, rw, http.StatusOK, "ok") } diff --git a/coderd/provisionerdserver/provisionerdserver.go b/coderd/provisionerdserver/provisionerdserver.go index 191143fdcd..6188ba8428 100644 --- a/coderd/provisionerdserver/provisionerdserver.go +++ b/coderd/provisionerdserver/provisionerdserver.go @@ -445,7 +445,7 @@ func (server *Server) UpdateJob(ctx context.Context, request *proto.UpdateJobReq if err != nil { return nil, xerrors.Errorf("parse job id: %w", err) } - server.Logger.Debug(ctx, "UpdateJob starting", slog.F("job_id", parsedID)) + server.Logger.Debug(ctx, "stage UpdateJob starting", slog.F("job_id", parsedID)) job, err := server.Database.GetProvisionerJobByID(ctx, parsedID) if err != nil { return nil, xerrors.Errorf("get job: %w", err) @@ -592,7 +592,7 @@ func (server *Server) FailJob(ctx context.Context, failJob *proto.FailedJob) (*p if err != nil { return nil, xerrors.Errorf("parse job id: %w", err) } - server.Logger.Debug(ctx, "FailJob starting", slog.F("job_id", jobID)) + server.Logger.Debug(ctx, "stage FailJob starting", slog.F("job_id", jobID)) job, err := server.Database.GetProvisionerJobByID(ctx, jobID) if err != nil { return nil, xerrors.Errorf("get provisioner job: %w", err) @@ -746,7 +746,7 @@ func (server *Server) CompleteJob(ctx context.Context, completed *proto.Complete if err != nil { return nil, xerrors.Errorf("parse job id: %w", err) } - server.Logger.Debug(ctx, "CompleteJob starting", slog.F("job_id", jobID)) + server.Logger.Debug(ctx, "stage CompleteJob starting", slog.F("job_id", jobID)) job, err := server.Database.GetProvisionerJobByID(ctx, jobID) if err != nil { return nil, xerrors.Errorf("get job by id: %w", err) @@ -1121,7 +1121,7 @@ func (server *Server) CompleteJob(ctx context.Context, completed *proto.Complete return nil, xerrors.Errorf("publish end of job logs: %w", err) } - server.Logger.Debug(ctx, "CompleteJob done", slog.F("job_id", jobID)) + server.Logger.Debug(ctx, "stage CompleteJob done", slog.F("job_id", jobID)) return &proto.Empty{}, nil } diff --git a/coderd/telemetry/telemetry.go b/coderd/telemetry/telemetry.go index b4d28537c4..ced52a58fd 100644 --- a/coderd/telemetry/telemetry.go +++ b/coderd/telemetry/telemetry.go @@ -125,7 +125,7 @@ func (r *remoteReporter) reportSync(snapshot *Snapshot) { } req, err := http.NewRequestWithContext(r.ctx, "POST", r.snapshotURL.String(), bytes.NewReader(data)) if err != nil { - r.options.Logger.Error(r.ctx, "create request", slog.Error(err)) + r.options.Logger.Error(r.ctx, "unable to create snapshot request", slog.Error(err)) return } req.Header.Set(VersionHeader, buildinfo.Version()) @@ -197,7 +197,7 @@ func (r *remoteReporter) reportWithDeployment() { // Submit deployment information before creating a snapshot! // This is separated from the snapshot API call to reduce // duplicate data from being inserted. Snapshot may be called - // numerous times simaltanously if there is lots of activity! + // numerous times simultaneously if there is lots of activity! err := r.deployment() if err != nil { r.options.Logger.Debug(r.ctx, "update deployment", slog.Error(err)) @@ -208,7 +208,7 @@ func (r *remoteReporter) reportWithDeployment() { return } if err != nil { - r.options.Logger.Error(r.ctx, "create snapshot", slog.Error(err)) + r.options.Logger.Error(r.ctx, "unable to create deployment snapshot", slog.Error(err)) return } r.reportSync(snapshot) diff --git a/coderd/userauth.go b/coderd/userauth.go index d9b87f1ca7..22b4350d01 100644 --- a/coderd/userauth.go +++ b/coderd/userauth.go @@ -678,7 +678,7 @@ func (api *API) userOIDC(rw http.ResponseWriter, r *http.Request) { // This conditional is purely to warn the user they might have misconfigured their OIDC // configuration. if _, groupClaimExists := claims["groups"]; !usingGroups && groupClaimExists { - api.Logger.Debug(ctx, "'groups' claim was returned, but 'oidc-group-field' is not set, check your coder oidc settings.") + api.Logger.Debug(ctx, "claim 'groups' was returned, but 'oidc-group-field' is not set, check your coder oidc settings") } // The username is a required property in Coder. We make a best-effort diff --git a/coderd/workspaceagents.go b/coderd/workspaceagents.go index 2c8d894868..e6ec7b4674 100644 --- a/coderd/workspaceagents.go +++ b/coderd/workspaceagents.go @@ -999,7 +999,7 @@ func (api *API) workspaceAgentCoordinate(rw http.ResponseWriter, r *http.Request } api.publishWorkspaceUpdate(ctx, build.WorkspaceID) - api.Logger.Info(ctx, "accepting agent", + api.Logger.Debug(ctx, "accepting agent", slog.F("owner", owner.Username), slog.F("workspace", workspace.Name), slog.F("name", workspaceAgent.Name), diff --git a/enterprise/derpmesh/derpmesh.go b/enterprise/derpmesh/derpmesh.go index 645b96cd31..c3f322e970 100644 --- a/enterprise/derpmesh/derpmesh.go +++ b/enterprise/derpmesh/derpmesh.go @@ -51,12 +51,12 @@ func (m *Mesh) SetAddresses(addresses []string, connect bool) { for _, address := range addresses { addressURL, err := url.Parse(address) if err != nil { - m.logger.Error(m.ctx, "invalid address", slog.F("address", address), slog.Error(err)) + m.logger.Error(m.ctx, "unable to parse DERP address", slog.F("address", address), slog.Error(err)) continue } derpURL, err := addressURL.Parse("/derp") if err != nil { - m.logger.Error(m.ctx, "parse derp", slog.F("address", addressURL.String()), slog.Error(err)) + m.logger.Error(m.ctx, "unable to parse DERP address with /derp", slog.F("address", addressURL.String()), slog.Error(err)) continue } address = derpURL.String() diff --git a/provisionerd/provisionerd.go b/provisionerd/provisionerd.go index cec7a1ffea..d7e50f96bf 100644 --- a/provisionerd/provisionerd.go +++ b/provisionerd/provisionerd.go @@ -190,7 +190,7 @@ func (p *Server) connect(ctx context.Context) { if p.isClosed() { return } - p.opts.Logger.Warn(context.Background(), "failed to dial", slog.Error(err)) + p.opts.Logger.Warn(context.Background(), "coderd client failed to dial", slog.Error(err)) continue } // Ensure connection is not left hanging during a race between @@ -303,7 +303,7 @@ func (p *Server) acquireJob(ctx context.Context) { return } if p.isShutdown() { - p.opts.Logger.Debug(context.Background(), "skipping acquire; provisionerd is shutting down...") + p.opts.Logger.Debug(context.Background(), "skipping acquire; provisionerd is shutting down") return } @@ -333,7 +333,7 @@ func (p *Server) acquireJob(ctx context.Context) { return } - p.opts.Logger.Warn(ctx, "acquire job", slog.Error(err)) + p.opts.Logger.Warn(ctx, "provisionerd was unable to acquire job", slog.Error(err)) return } if job.JobId == "" { @@ -384,7 +384,7 @@ func (p *Server) acquireJob(ctx context.Context) { ) } - p.opts.Logger.Info(ctx, "acquired job", fields...) + p.opts.Logger.Debug(ctx, "acquired job", fields...) provisioner, ok := p.opts.Provisioners[job.Provisioner] if !ok { @@ -393,7 +393,7 @@ func (p *Server) acquireJob(ctx context.Context) { Error: fmt.Sprintf("no provisioner %s", job.Provisioner), }) if err != nil { - p.opts.Logger.Error(ctx, "fail job", slog.F("job_id", job.JobId), slog.Error(err)) + p.opts.Logger.Error(ctx, "provisioner job failed", slog.F("job_id", job.JobId), slog.Error(err)) } return } diff --git a/provisionerd/runner/runner.go b/provisionerd/runner/runner.go index 7d81ea567b..1db005aab9 100644 --- a/provisionerd/runner/runner.go +++ b/provisionerd/runner/runner.go @@ -223,17 +223,17 @@ func (r *Runner) Run() { r.logger.Debug(ctx, "sending FailedJob") err := r.sender.FailJob(ctx, r.failedJob) if err != nil { - r.logger.Error(ctx, "send FailJob", slog.Error(err)) + r.logger.Error(ctx, "sending FailJob failed", slog.Error(err)) } else { - r.logger.Info(ctx, "sent FailedJob") + r.logger.Debug(ctx, "sent FailedJob") } } else { r.logger.Debug(ctx, "sending CompletedJob") err := r.sender.CompleteJob(ctx, r.completedJob) if err != nil { - r.logger.Error(ctx, "send CompletedJob", slog.Error(err)) + r.logger.Error(ctx, "sending CompletedJob failed", slog.Error(err)) } else { - r.logger.Info(ctx, "sent CompletedJob") + r.logger.Debug(ctx, "sent CompletedJob") } } close(r.done) @@ -553,7 +553,7 @@ func (r *Runner) heartbeatRoutine(ctx context.Context) { timer := time.NewTimer(r.forceCancelInterval) select { case <-timer.C: - r.logger.Warn(ctx, "Cancel timed out") + r.logger.Debug(ctx, "cancel timed out") err := r.Fail(ctx, r.failedJobf("Cancel timed out")) if err != nil { r.logger.Warn(ctx, "failed to call FailJob", slog.Error(err)) @@ -706,7 +706,7 @@ func (r *Runner) runTemplateImportParse(ctx context.Context) ([]*sdkproto.Templa Stage: "Parse parameters", }) case *sdkproto.Parse_Response_Complete: - r.logger.Info(context.Background(), "parse complete", + r.logger.Debug(context.Background(), "parse complete", slog.F("template_variables", msgType.Complete.TemplateVariables), ) diff --git a/scripts/rules.go b/scripts/rules.go index 0f3dffe891..20d0c43f7b 100644 --- a/scripts/rules.go +++ b/scripts/rules.go @@ -319,13 +319,24 @@ func slogMessageFormat(m dsl.Matcher) { m.Import("cdr.dev/slog") m.Match( `logger.Error($ctx, $message, $*args)`, - `Logger.Error($ctx, $message, $*args)`, `logger.Warn($ctx, $message, $*args)`, - `Logger.Warn($ctx, $message, $*args)`, `logger.Info($ctx, $message, $*args)`, - `Logger.Info($ctx, $message, $*args)`, `logger.Debug($ctx, $message, $*args)`, + + `$foo.logger.Error($ctx, $message, $*args)`, + `$foo.logger.Warn($ctx, $message, $*args)`, + `$foo.logger.Info($ctx, $message, $*args)`, + `$foo.logger.Debug($ctx, $message, $*args)`, + + `Logger.Error($ctx, $message, $*args)`, + `Logger.Warn($ctx, $message, $*args)`, + `Logger.Info($ctx, $message, $*args)`, `Logger.Debug($ctx, $message, $*args)`, + + `$foo.Logger.Error($ctx, $message, $*args)`, + `$foo.Logger.Warn($ctx, $message, $*args)`, + `$foo.Logger.Info($ctx, $message, $*args)`, + `$foo.Logger.Debug($ctx, $message, $*args)`, ). Where( ( @@ -334,7 +345,10 @@ func slogMessageFormat(m dsl.Matcher) { // it starts with lowercase: m["message"].Text.Matches(`^"[A-Z]{1}`) && // but there are exceptions: - !m["message"].Text.Matches(`^"Prometheus`))). + !m["message"].Text.Matches(`^"Prometheus`) && + !m["message"].Text.Matches(`^"X11`) && + !m["message"].Text.Matches(`^"CSP`) && + !m["message"].Text.Matches(`^"OIDC`))). Report(`Message $message must start with lowercase, and does not end with a special characters.`) } @@ -343,11 +357,21 @@ func slogMessageLength(m dsl.Matcher) { m.Import("cdr.dev/slog") m.Match( `logger.Error($ctx, $message, $*args)`, - `Logger.Error($ctx, $message, $*args)`, `logger.Warn($ctx, $message, $*args)`, - `Logger.Warn($ctx, $message, $*args)`, `logger.Info($ctx, $message, $*args)`, + + `$foo.logger.Error($ctx, $message, $*args)`, + `$foo.logger.Warn($ctx, $message, $*args)`, + `$foo.logger.Info($ctx, $message, $*args)`, + + `Logger.Error($ctx, $message, $*args)`, + `Logger.Warn($ctx, $message, $*args)`, `Logger.Info($ctx, $message, $*args)`, + + `$foo.Logger.Error($ctx, $message, $*args)`, + `$foo.Logger.Warn($ctx, $message, $*args)`, + `$foo.Logger.Info($ctx, $message, $*args)`, + // no debug ). Where(