chore: ensure logs consistency across Coder (#8083)

This commit is contained in:
Marcin Tojek
2023-06-20 12:30:45 +02:00
committed by GitHub
parent d6f8bd7847
commit b1d1b63113
19 changed files with 132 additions and 57 deletions

View File

@ -71,11 +71,11 @@ func (h *HTTPAuthorizer) Authorize(r *http.Request, action rbac.Action, object r
internalError := new(rbac.UnauthorizedError)
logger := h.Logger
if xerrors.As(err, internalError) {
logger = h.Logger.With(slog.F("internal", internalError.Internal()))
logger = h.Logger.With(slog.F("internal_error", internalError.Internal()))
}
// Log information for debugging. This will be very helpful
// in the early days
logger.Warn(r.Context(), "unauthorized",
logger.Warn(r.Context(), "requester is not authorized to access the object",
slog.F("roles", roles.Actor.SafeRoleNames()),
slog.F("actor_id", roles.Actor.ID),
slog.F("actor_name", roles.ActorName),

View File

@ -245,9 +245,9 @@ func New(options *Options) *API {
options.TracerProvider = trace.NewNoopTracerProvider()
}
if options.SetUserGroups == nil {
options.SetUserGroups = func(ctx context.Context, _ database.Store, id uuid.UUID, groups []string) error {
options.SetUserGroups = func(ctx context.Context, _ database.Store, userID uuid.UUID, groups []string) error {
options.Logger.Warn(ctx, "attempted to assign OIDC groups without enterprise license",
slog.F("id", id), slog.F("groups", groups),
slog.F("user_id", userID), slog.F("groups", groups),
)
return nil
}

View File

@ -69,7 +69,7 @@ func logNotAuthorizedError(ctx context.Context, logger slog.Logger, err error) e
return &contextError
}
logger.Debug(ctx, "unauthorized",
slog.F("internal", internalError.Internal()),
slog.F("internal_error", internalError.Internal()),
slog.F("input", internalError.Input()),
slog.Error(err),
)

View File

@ -50,7 +50,7 @@ func ReportCLITelemetry(log slog.Logger, rep telemetry.Reporter) func(http.Handl
log.Error(
r.Context(),
"base64 decode",
slog.F("error", err),
slog.Error(err),
)
return
}

View File

@ -222,7 +222,7 @@ func Agents(ctx context.Context, logger slog.Logger, registerer prometheus.Regis
case <-ticker.C:
}
logger.Debug(ctx, "Agent metrics collection is starting")
logger.Debug(ctx, "agent metrics collection is starting")
timer := prometheus.NewTimer(metricsCollectorAgents)
workspaceRows, err := db.GetWorkspaces(ctx, database.GetWorkspacesParams{
@ -236,7 +236,7 @@ func Agents(ctx context.Context, logger slog.Logger, registerer prometheus.Regis
for _, workspace := range workspaceRows {
user, err := db.GetUserByID(ctx, workspace.OwnerID)
if err != nil {
logger.Error(ctx, "can't get user", slog.F("user_id", workspace.OwnerID), slog.Error(err))
logger.Error(ctx, "can't get user from the database", slog.F("user_id", workspace.OwnerID), slog.Error(err))
agentsGauge.WithLabelValues(VectorOperationAdd, 0, user.Username, workspace.Name)
continue
}
@ -314,7 +314,7 @@ func Agents(ctx context.Context, logger slog.Logger, registerer prometheus.Regis
agentsAppsGauge.Commit()
done:
logger.Debug(ctx, "Agent metrics collection is done")
logger.Debug(ctx, "agent metrics collection is done")
timer.ObserveDuration()
ticker.Reset(duration)
}
@ -447,7 +447,7 @@ func AgentStats(ctx context.Context, logger slog.Logger, registerer prometheus.R
case <-ticker.C:
}
logger.Debug(ctx, "Agent metrics collection is starting")
logger.Debug(ctx, "agent metrics collection is starting")
timer := prometheus.NewTimer(metricsCollectorAgentStats)
checkpoint := time.Now()
@ -482,7 +482,7 @@ func AgentStats(ctx context.Context, logger slog.Logger, registerer prometheus.R
}
}
logger.Debug(ctx, "Agent metrics collection is done", slog.F("len", len(stats)))
logger.Debug(ctx, "agent metrics collection is done", slog.F("len", len(stats)))
timer.ObserveDuration()
createdAfter = checkpoint

View File

@ -108,7 +108,7 @@ func (server *Server) AcquireJob(ctx context.Context, _ *proto.Empty) (*proto.Ac
if err != nil {
return nil, xerrors.Errorf("acquire job: %w", err)
}
server.Logger.Debug(ctx, "locked job from database", slog.F("id", job.ID))
server.Logger.Debug(ctx, "locked job from database", slog.F("job_id", job.ID))
// Marks the acquired job as failed with the error message provided.
failJob := func(errorMessage string) error {

View File

@ -56,7 +56,7 @@ func (api *API) provisionerJobLogs(rw http.ResponseWriter, r *http.Request, job
}
if !follow {
fetchAndWriteLogs(ctx, logger, api.Database, job.ID, after, rw)
fetchAndWriteLogs(ctx, api.Database, job.ID, after, rw)
return
}
@ -222,7 +222,7 @@ func convertProvisionerJob(provisionerJob database.ProvisionerJob) codersdk.Prov
return job
}
func fetchAndWriteLogs(ctx context.Context, logger slog.Logger, db database.Store, jobID uuid.UUID, after int64, rw http.ResponseWriter) {
func fetchAndWriteLogs(ctx context.Context, db database.Store, jobID uuid.UUID, after int64, rw http.ResponseWriter) {
logs, err := db.GetProvisionerLogsAfterID(ctx, database.GetProvisionerLogsAfterIDParams{
JobID: jobID,
CreatedAfter: after,
@ -237,8 +237,6 @@ func fetchAndWriteLogs(ctx context.Context, logger slog.Logger, db database.Stor
if logs == nil {
logs = []database.ProvisionerJobLog{}
}
logger.Debug(ctx, "Finished non-follow job logs")
httpapi.Write(ctx, rw, http.StatusOK, convertProvisionerJobLogs(logs))
}
@ -259,7 +257,7 @@ func jobIsComplete(logger slog.Logger, job database.ProvisionerJob) bool {
return false
default:
logger.Error(context.Background(),
"unknown status",
"can't convert the provisioner job status",
slog.F("job_id", job.ID), slog.F("status", status))
return false
}

View File

@ -464,7 +464,6 @@ func (api *API) workspaceAgentStartupLogs(rw http.ResponseWriter, r *http.Reques
}
if !follow {
logger.Debug(ctx, "Finished non-follow job logs")
httpapi.Write(ctx, rw, http.StatusOK, convertWorkspaceAgentStartupLogs(logs))
return
}
@ -967,7 +966,7 @@ func (api *API) workspaceAgentCoordinate(rw http.ResponseWriter, r *http.Request
if !xerrors.Is(err, context.Canceled) && !database.IsQueryCanceledError(err) {
api.Logger.Error(ctx, "failed to update agent disconnect time",
slog.Error(err),
slog.F("workspace", build.WorkspaceID),
slog.F("workspace_id", build.WorkspaceID),
)
}
}
@ -1256,8 +1255,8 @@ func (api *API) workspaceAgentReportStats(rw http.ResponseWriter, r *http.Reques
api.Logger.Debug(ctx, "read stats report",
slog.F("interval", api.AgentStatsRefreshInterval),
slog.F("agent", workspaceAgent.ID),
slog.F("workspace", workspace.ID),
slog.F("workspace_agent_id", workspaceAgent.ID),
slog.F("workspace_id", workspace.ID),
slog.F("payload", req),
)
@ -1267,7 +1266,7 @@ func (api *API) workspaceAgentReportStats(rw http.ResponseWriter, r *http.Reques
payload, err := json.Marshal(req.ConnectionsByProto)
if err != nil {
api.Logger.Error(ctx, "marshal agent connections by proto", slog.F("workspace_agent", workspaceAgent.ID), slog.Error(err))
api.Logger.Error(ctx, "marshal agent connections by proto", slog.F("workspace_agent_id", workspaceAgent.ID), slog.Error(err))
payload = json.RawMessage("{}")
}
@ -1399,8 +1398,8 @@ func (api *API) workspaceAgentPostMetadata(rw http.ResponseWriter, r *http.Reque
api.Logger.Debug(
ctx, "accepted metadata report",
slog.F("agent", workspaceAgent.ID),
slog.F("workspace", workspace.ID),
slog.F("workspace_agent_id", workspaceAgent.ID),
slog.F("workspace_id", workspace.ID),
slog.F("collected_at", datum.CollectedAt),
slog.F("key", datum.Key),
)
@ -1577,8 +1576,8 @@ func (api *API) workspaceAgentReportLifecycle(rw http.ResponseWriter, r *http.Re
}
logger := api.Logger.With(
slog.F("agent", workspaceAgent.ID),
slog.F("workspace", workspace.ID),
slog.F("workspace_agent_id", workspaceAgent.ID),
slog.F("workspace_id", workspace.ID),
slog.F("payload", req),
)
logger.Debug(ctx, "workspace agent state report")