From 67cec02ed13e726d39ef030167bccdd67c2b0313 Mon Sep 17 00:00:00 2001 From: Michael Suchacz <203725896+ibetitsmike@users.noreply.github.com> Date: Tue, 15 Apr 2025 13:27:23 +0200 Subject: [PATCH] feat: extend request logs with auth & DB info (#17304) Closes #16903 --- Makefile | 8 +- coderd/coderd.go | 3 +- coderd/database/dbauthz/dbauthz.go | 31 ++-- coderd/database/queries.sql.go | 6 +- coderd/database/queries/users.sql | 4 +- coderd/httpmw/apikey.go | 2 + coderd/httpmw/{ => loggermw}/logger.go | 78 +++++++++- .../{ => loggermw}/logger_internal_test.go | 141 +++++++++++++++++- .../{ => loggermw}/loggermock/loggermock.go | 15 +- coderd/httpmw/workspaceagentparam.go | 11 ++ coderd/httpmw/workspaceparam.go | 15 ++ coderd/inboxnotifications.go | 3 +- coderd/provisionerjobs.go | 3 +- coderd/provisionerjobs_internal_test.go | 6 +- coderd/rbac/authz.go | 25 ++++ coderd/workspaceagents.go | 7 +- enterprise/coderd/provisionerdaemons.go | 3 +- enterprise/wsproxy/wsproxy.go | 3 +- tailnet/test/integration/integration.go | 4 +- 19 files changed, 334 insertions(+), 34 deletions(-) rename coderd/httpmw/{ => loggermw}/logger.go (62%) rename coderd/httpmw/{ => loggermw}/logger_internal_test.go (56%) rename coderd/httpmw/{ => loggermw}/loggermock/loggermock.go (77%) diff --git a/Makefile b/Makefile index 6486f5cbed5fa..4ada1cd6d488c 100644 --- a/Makefile +++ b/Makefile @@ -582,7 +582,7 @@ GEN_FILES := \ coderd/database/pubsub/psmock/psmock.go \ agent/agentcontainers/acmock/acmock.go \ agent/agentcontainers/dcspec/dcspec_gen.go \ - coderd/httpmw/loggermock/loggermock.go + coderd/httpmw/loggermw/loggermock/loggermock.go # all gen targets should be added here and to gen/mark-fresh gen: gen/db gen/golden-files $(GEN_FILES) @@ -631,7 +631,7 @@ gen/mark-fresh: coderd/database/pubsub/psmock/psmock.go \ agent/agentcontainers/acmock/acmock.go \ agent/agentcontainers/dcspec/dcspec_gen.go \ - coderd/httpmw/loggermock/loggermock.go \ + coderd/httpmw/loggermw/loggermock/loggermock.go \ " for file in $$files; do @@ -671,8 +671,8 @@ agent/agentcontainers/acmock/acmock.go: agent/agentcontainers/containers.go go generate ./agent/agentcontainers/acmock/ touch "$@" -coderd/httpmw/loggermock/loggermock.go: coderd/httpmw/logger.go - go generate ./coderd/httpmw/loggermock/ +coderd/httpmw/loggermw/loggermock/loggermock.go: coderd/httpmw/loggermw/logger.go + go generate ./coderd/httpmw/loggermw/loggermock/ touch "$@" agent/agentcontainers/dcspec/dcspec_gen.go: \ diff --git a/coderd/coderd.go b/coderd/coderd.go index 283fcaf08eba6..f5b0bcbefc48c 100644 --- a/coderd/coderd.go +++ b/coderd/coderd.go @@ -64,6 +64,7 @@ import ( "github.com/coder/coder/v2/coderd/healthcheck/derphealth" "github.com/coder/coder/v2/coderd/httpapi" "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/metricscache" "github.com/coder/coder/v2/coderd/notifications" "github.com/coder/coder/v2/coderd/portsharing" @@ -801,7 +802,7 @@ func New(options *Options) *API { tracing.Middleware(api.TracerProvider), httpmw.AttachRequestID, httpmw.ExtractRealIP(api.RealIPConfig), - httpmw.Logger(api.Logger), + loggermw.Logger(api.Logger), singleSlashMW, rolestore.CustomRoleMW, prometheusMW, diff --git a/coderd/database/dbauthz/dbauthz.go b/coderd/database/dbauthz/dbauthz.go index 7ab078d32ad4f..ed1242f674d0f 100644 --- a/coderd/database/dbauthz/dbauthz.go +++ b/coderd/database/dbauthz/dbauthz.go @@ -24,6 +24,7 @@ import ( "github.com/coder/coder/v2/coderd/database" "github.com/coder/coder/v2/coderd/database/dbtime" "github.com/coder/coder/v2/coderd/httpapi/httpapiconstraints" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/rbac" "github.com/coder/coder/v2/coderd/util/slice" "github.com/coder/coder/v2/provisionersdk" @@ -162,6 +163,7 @@ func ActorFromContext(ctx context.Context) (rbac.Subject, bool) { var ( subjectProvisionerd = rbac.Subject{ + Type: rbac.SubjectTypeProvisionerd, FriendlyName: "Provisioner Daemon", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -196,6 +198,7 @@ var ( }.WithCachedASTValue() subjectAutostart = rbac.Subject{ + Type: rbac.SubjectTypeAutostart, FriendlyName: "Autostart", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -219,6 +222,7 @@ var ( // See unhanger package. subjectHangDetector = rbac.Subject{ + Type: rbac.SubjectTypeHangDetector, FriendlyName: "Hang Detector", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -239,6 +243,7 @@ var ( // See cryptokeys package. subjectCryptoKeyRotator = rbac.Subject{ + Type: rbac.SubjectTypeCryptoKeyRotator, FriendlyName: "Crypto Key Rotator", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -257,6 +262,7 @@ var ( // See cryptokeys package. subjectCryptoKeyReader = rbac.Subject{ + Type: rbac.SubjectTypeCryptoKeyReader, FriendlyName: "Crypto Key Reader", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -274,6 +280,7 @@ var ( }.WithCachedASTValue() subjectNotifier = rbac.Subject{ + Type: rbac.SubjectTypeNotifier, FriendlyName: "Notifier", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -294,6 +301,7 @@ var ( }.WithCachedASTValue() subjectResourceMonitor = rbac.Subject{ + Type: rbac.SubjectTypeResourceMonitor, FriendlyName: "Resource Monitor", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -312,6 +320,7 @@ var ( }.WithCachedASTValue() subjectSystemRestricted = rbac.Subject{ + Type: rbac.SubjectTypeSystemRestricted, FriendlyName: "System", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -346,6 +355,7 @@ var ( }.WithCachedASTValue() subjectSystemReadProvisionerDaemons = rbac.Subject{ + Type: rbac.SubjectTypeSystemReadProvisionerDaemons, FriendlyName: "Provisioner Daemons Reader", ID: uuid.Nil.String(), Roles: rbac.Roles([]rbac.Role{ @@ -366,53 +376,53 @@ var ( // AsProvisionerd returns a context with an actor that has permissions required // for provisionerd to function. func AsProvisionerd(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectProvisionerd) + return As(ctx, subjectProvisionerd) } // AsAutostart returns a context with an actor that has permissions required // for autostart to function. func AsAutostart(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectAutostart) + return As(ctx, subjectAutostart) } // AsHangDetector returns a context with an actor that has permissions required // for unhanger.Detector to function. func AsHangDetector(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectHangDetector) + return As(ctx, subjectHangDetector) } // AsKeyRotator returns a context with an actor that has permissions required for rotating crypto keys. func AsKeyRotator(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectCryptoKeyRotator) + return As(ctx, subjectCryptoKeyRotator) } // AsKeyReader returns a context with an actor that has permissions required for reading crypto keys. func AsKeyReader(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectCryptoKeyReader) + return As(ctx, subjectCryptoKeyReader) } // AsNotifier returns a context with an actor that has permissions required for // creating/reading/updating/deleting notifications. func AsNotifier(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectNotifier) + return As(ctx, subjectNotifier) } // AsResourceMonitor returns a context with an actor that has permissions required for // updating resource monitors. func AsResourceMonitor(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectResourceMonitor) + return As(ctx, subjectResourceMonitor) } // AsSystemRestricted returns a context with an actor that has permissions // required for various system operations (login, logout, metrics cache). func AsSystemRestricted(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectSystemRestricted) + return As(ctx, subjectSystemRestricted) } // AsSystemReadProvisionerDaemons returns a context with an actor that has permissions // to read provisioner daemons. func AsSystemReadProvisionerDaemons(ctx context.Context) context.Context { - return context.WithValue(ctx, authContextKey{}, subjectSystemReadProvisionerDaemons) + return As(ctx, subjectSystemReadProvisionerDaemons) } var AsRemoveActor = rbac.Subject{ @@ -430,6 +440,9 @@ func As(ctx context.Context, actor rbac.Subject) context.Context { // should be removed from the context. return context.WithValue(ctx, authContextKey{}, nil) } + if rlogger := loggermw.RequestLoggerFromContext(ctx); rlogger != nil { + rlogger.WithAuthContext(actor) + } return context.WithValue(ctx, authContextKey{}, actor) } diff --git a/coderd/database/queries.sql.go b/coderd/database/queries.sql.go index 37c78947eedfc..4268e802fe4a2 100644 --- a/coderd/database/queries.sql.go +++ b/coderd/database/queries.sql.go @@ -11628,10 +11628,10 @@ func (q *sqlQuerier) GetActiveUserCount(ctx context.Context, includeSystem bool) const getAuthorizationUserRoles = `-- name: GetAuthorizationUserRoles :one SELECT - -- username is returned just to help for logging purposes + -- username and email are returned just to help for logging purposes -- status is used to enforce 'suspended' users, as all roles are ignored -- when suspended. - id, username, status, + id, username, status, email, -- All user roles, including their org roles. array_cat( -- All users are members @@ -11672,6 +11672,7 @@ type GetAuthorizationUserRolesRow struct { ID uuid.UUID `db:"id" json:"id"` Username string `db:"username" json:"username"` Status UserStatus `db:"status" json:"status"` + Email string `db:"email" json:"email"` Roles []string `db:"roles" json:"roles"` Groups []string `db:"groups" json:"groups"` } @@ -11685,6 +11686,7 @@ func (q *sqlQuerier) GetAuthorizationUserRoles(ctx context.Context, userID uuid. &i.ID, &i.Username, &i.Status, + &i.Email, pq.Array(&i.Roles), pq.Array(&i.Groups), ) diff --git a/coderd/database/queries/users.sql b/coderd/database/queries/users.sql index c4304cfc3e60e..ebf0e10b5d61c 100644 --- a/coderd/database/queries/users.sql +++ b/coderd/database/queries/users.sql @@ -271,10 +271,10 @@ WHERE -- This function returns roles for authorization purposes. Implied member roles -- are included. SELECT - -- username is returned just to help for logging purposes + -- username and email are returned just to help for logging purposes -- status is used to enforce 'suspended' users, as all roles are ignored -- when suspended. - id, username, status, + id, username, status, email, -- All user roles, including their org roles. array_cat( -- All users are members diff --git a/coderd/httpmw/apikey.go b/coderd/httpmw/apikey.go index 1574affa30b65..d614b37a3d897 100644 --- a/coderd/httpmw/apikey.go +++ b/coderd/httpmw/apikey.go @@ -465,7 +465,9 @@ func UserRBACSubject(ctx context.Context, db database.Store, userID uuid.UUID, s } actor := rbac.Subject{ + Type: rbac.SubjectTypeUser, FriendlyName: roles.Username, + Email: roles.Email, ID: userID.String(), Roles: rbacRoles, Groups: roles.Groups, diff --git a/coderd/httpmw/logger.go b/coderd/httpmw/loggermw/logger.go similarity index 62% rename from coderd/httpmw/logger.go rename to coderd/httpmw/loggermw/logger.go index 0da964407b3e4..9eeb07a5f10e5 100644 --- a/coderd/httpmw/logger.go +++ b/coderd/httpmw/loggermw/logger.go @@ -1,13 +1,17 @@ -package httpmw +package loggermw import ( "context" "fmt" "net/http" + "sync" "time" + "github.com/go-chi/chi/v5" + "cdr.dev/slog" "github.com/coder/coder/v2/coderd/httpapi" + "github.com/coder/coder/v2/coderd/rbac" "github.com/coder/coder/v2/coderd/tracing" ) @@ -62,6 +66,7 @@ func Logger(log slog.Logger) func(next http.Handler) http.Handler { type RequestLogger interface { WithFields(fields ...slog.Field) WriteLog(ctx context.Context, status int) + WithAuthContext(actor rbac.Subject) } type SlogRequestLogger struct { @@ -69,6 +74,9 @@ type SlogRequestLogger struct { written bool message string start time.Time + // Protects actors map for concurrent writes. + mu sync.RWMutex + actors map[rbac.SubjectType]rbac.Subject } var _ RequestLogger = &SlogRequestLogger{} @@ -79,6 +87,7 @@ func NewRequestLogger(log slog.Logger, message string, start time.Time) RequestL written: false, message: message, start: start, + actors: make(map[rbac.SubjectType]rbac.Subject), } } @@ -86,6 +95,52 @@ func (c *SlogRequestLogger) WithFields(fields ...slog.Field) { c.log = c.log.With(fields...) } +func (c *SlogRequestLogger) WithAuthContext(actor rbac.Subject) { + c.mu.Lock() + defer c.mu.Unlock() + c.actors[actor.Type] = actor +} + +func (c *SlogRequestLogger) addAuthContextFields() { + c.mu.RLock() + defer c.mu.RUnlock() + + usr, ok := c.actors[rbac.SubjectTypeUser] + if ok { + c.log = c.log.With( + slog.F("requestor_id", usr.ID), + slog.F("requestor_name", usr.FriendlyName), + slog.F("requestor_email", usr.Email), + ) + } else { + // If there is no user, we log the requestor name for the first + // actor in a defined order. + for _, v := range actorLogOrder { + subj, ok := c.actors[v] + if !ok { + continue + } + c.log = c.log.With( + slog.F("requestor_name", subj.FriendlyName), + ) + break + } + } +} + +var actorLogOrder = []rbac.SubjectType{ + rbac.SubjectTypeAutostart, + rbac.SubjectTypeCryptoKeyReader, + rbac.SubjectTypeCryptoKeyRotator, + rbac.SubjectTypeHangDetector, + rbac.SubjectTypeNotifier, + rbac.SubjectTypePrebuildsOrchestrator, + rbac.SubjectTypeProvisionerd, + rbac.SubjectTypeResourceMonitor, + rbac.SubjectTypeSystemReadProvisionerDaemons, + rbac.SubjectTypeSystemRestricted, +} + func (c *SlogRequestLogger) WriteLog(ctx context.Context, status int) { if c.written { return @@ -93,11 +148,32 @@ func (c *SlogRequestLogger) WriteLog(ctx context.Context, status int) { c.written = true end := time.Now() + // Right before we write the log, we try to find the user in the actors + // and add the fields to the log. + c.addAuthContextFields() + logger := c.log.With( slog.F("took", end.Sub(c.start)), slog.F("status_code", status), slog.F("latency_ms", float64(end.Sub(c.start)/time.Millisecond)), ) + + // If the request is routed, add the route parameters to the log. + if chiCtx := chi.RouteContext(ctx); chiCtx != nil { + urlParams := chiCtx.URLParams + routeParamsFields := make([]slog.Field, 0, len(urlParams.Keys)) + + for k, v := range urlParams.Keys { + if urlParams.Values[k] != "" { + routeParamsFields = append(routeParamsFields, slog.F("params_"+v, urlParams.Values[k])) + } + } + + if len(routeParamsFields) > 0 { + logger = logger.With(routeParamsFields...) + } + } + // We already capture most of this information in the span (minus // the response body which we don't want to capture anyways). tracing.RunWithoutSpan(ctx, func(ctx context.Context) { diff --git a/coderd/httpmw/logger_internal_test.go b/coderd/httpmw/loggermw/logger_internal_test.go similarity index 56% rename from coderd/httpmw/logger_internal_test.go rename to coderd/httpmw/loggermw/logger_internal_test.go index d3035e50d98c9..e88f8a69c178e 100644 --- a/coderd/httpmw/logger_internal_test.go +++ b/coderd/httpmw/loggermw/logger_internal_test.go @@ -1,13 +1,16 @@ -package httpmw +package loggermw import ( "context" "net/http" "net/http/httptest" + "slices" + "strings" "sync" "testing" "time" + "github.com/go-chi/chi/v5" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -79,7 +82,7 @@ func TestLoggerMiddleware_SingleRequest(t *testing.T) { require.Equal(t, sink.entries[0].Message, "GET") - fieldsMap := make(map[string]interface{}) + fieldsMap := make(map[string]any) for _, field := range sink.entries[0].Fields { fieldsMap[field.Name] = field.Value } @@ -156,6 +159,140 @@ func TestLoggerMiddleware_WebSocket(t *testing.T) { require.Len(t, sink.entries, 1, "log was written twice") } +func TestRequestLogger_HTTPRouteParams(t *testing.T) { + t.Parallel() + + sink := &fakeSink{} + logger := slog.Make(sink) + logger = logger.Leveled(slog.LevelDebug) + + ctx, cancel := context.WithTimeout(context.Background(), testutil.WaitShort) + defer cancel() + + chiCtx := chi.NewRouteContext() + chiCtx.URLParams.Add("workspace", "test-workspace") + chiCtx.URLParams.Add("agent", "test-agent") + + ctx = context.WithValue(ctx, chi.RouteCtxKey, chiCtx) + + // Create a test handler to simulate an HTTP request + testHandler := http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { + rw.WriteHeader(http.StatusOK) + _, _ = rw.Write([]byte("OK")) + }) + + // Wrap the test handler with the Logger middleware + loggerMiddleware := Logger(logger) + wrappedHandler := loggerMiddleware(testHandler) + + // Create a test HTTP request + req, err := http.NewRequestWithContext(ctx, http.MethodGet, "/test-path/}", nil) + require.NoError(t, err, "failed to create request") + + sw := &tracing.StatusWriter{ResponseWriter: httptest.NewRecorder()} + + // Serve the request + wrappedHandler.ServeHTTP(sw, req) + + fieldsMap := make(map[string]any) + for _, field := range sink.entries[0].Fields { + fieldsMap[field.Name] = field.Value + } + + // Check that the log contains the expected fields + requiredFields := []string{"workspace", "agent"} + for _, field := range requiredFields { + _, exists := fieldsMap["params_"+field] + require.True(t, exists, "field %q is missing in log fields", field) + } +} + +func TestRequestLogger_RouteParamsLogging(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + params map[string]string + expectedFields []string + }{ + { + name: "EmptyParams", + params: map[string]string{}, + expectedFields: []string{}, + }, + { + name: "SingleParam", + params: map[string]string{ + "workspace": "test-workspace", + }, + expectedFields: []string{"params_workspace"}, + }, + { + name: "MultipleParams", + params: map[string]string{ + "workspace": "test-workspace", + "agent": "test-agent", + "user": "test-user", + }, + expectedFields: []string{"params_workspace", "params_agent", "params_user"}, + }, + { + name: "EmptyValueParam", + params: map[string]string{ + "workspace": "test-workspace", + "agent": "", + }, + expectedFields: []string{"params_workspace"}, + }, + } + + for _, tt := range tests { + tt := tt + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + sink := &fakeSink{} + logger := slog.Make(sink) + logger = logger.Leveled(slog.LevelDebug) + + // Create a route context with the test parameters + chiCtx := chi.NewRouteContext() + for key, value := range tt.params { + chiCtx.URLParams.Add(key, value) + } + + ctx := context.WithValue(context.Background(), chi.RouteCtxKey, chiCtx) + logCtx := NewRequestLogger(logger, "GET", time.Now()) + + // Write the log + logCtx.WriteLog(ctx, http.StatusOK) + + require.Len(t, sink.entries, 1, "expected exactly one log entry") + + // Convert fields to map for easier checking + fieldsMap := make(map[string]any) + for _, field := range sink.entries[0].Fields { + fieldsMap[field.Name] = field.Value + } + + // Verify expected fields are present + for _, field := range tt.expectedFields { + value, exists := fieldsMap[field] + require.True(t, exists, "field %q should be present in log", field) + require.Equal(t, tt.params[strings.TrimPrefix(field, "params_")], value, "field %q has incorrect value", field) + } + + // Verify no unexpected fields are present + for field := range fieldsMap { + if field == "took" || field == "status_code" || field == "latency_ms" { + continue // Skip standard fields + } + require.True(t, slices.Contains(tt.expectedFields, field), "unexpected field %q in log", field) + } + }) + } +} + type fakeSink struct { entries []slog.SinkEntry newEntries chan slog.SinkEntry diff --git a/coderd/httpmw/loggermock/loggermock.go b/coderd/httpmw/loggermw/loggermock/loggermock.go similarity index 77% rename from coderd/httpmw/loggermock/loggermock.go rename to coderd/httpmw/loggermw/loggermock/loggermock.go index 47818ca11d9e6..008f862107ae6 100644 --- a/coderd/httpmw/loggermock/loggermock.go +++ b/coderd/httpmw/loggermw/loggermock/loggermock.go @@ -1,5 +1,5 @@ // Code generated by MockGen. DO NOT EDIT. -// Source: github.com/coder/coder/v2/coderd/httpmw (interfaces: RequestLogger) +// Source: github.com/coder/coder/v2/coderd/httpmw/loggermw (interfaces: RequestLogger) // // Generated by this command: // @@ -14,6 +14,7 @@ import ( reflect "reflect" slog "cdr.dev/slog" + rbac "github.com/coder/coder/v2/coderd/rbac" gomock "go.uber.org/mock/gomock" ) @@ -41,6 +42,18 @@ func (m *MockRequestLogger) EXPECT() *MockRequestLoggerMockRecorder { return m.recorder } +// WithAuthContext mocks base method. +func (m *MockRequestLogger) WithAuthContext(actor rbac.Subject) { + m.ctrl.T.Helper() + m.ctrl.Call(m, "WithAuthContext", actor) +} + +// WithAuthContext indicates an expected call of WithAuthContext. +func (mr *MockRequestLoggerMockRecorder) WithAuthContext(actor any) *gomock.Call { + mr.mock.ctrl.T.Helper() + return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "WithAuthContext", reflect.TypeOf((*MockRequestLogger)(nil).WithAuthContext), actor) +} + // WithFields mocks base method. func (m *MockRequestLogger) WithFields(fields ...slog.Field) { m.ctrl.T.Helper() diff --git a/coderd/httpmw/workspaceagentparam.go b/coderd/httpmw/workspaceagentparam.go index a47ce3c377ae0..434e057c0eccc 100644 --- a/coderd/httpmw/workspaceagentparam.go +++ b/coderd/httpmw/workspaceagentparam.go @@ -6,8 +6,11 @@ import ( "github.com/go-chi/chi/v5" + "cdr.dev/slog" + "github.com/coder/coder/v2/coderd/database" "github.com/coder/coder/v2/coderd/httpapi" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/codersdk" ) @@ -81,6 +84,14 @@ func ExtractWorkspaceAgentParam(db database.Store) func(http.Handler) http.Handl ctx = context.WithValue(ctx, workspaceAgentParamContextKey{}, agent) chi.RouteContext(ctx).URLParams.Add("workspace", build.WorkspaceID.String()) + + if rlogger := loggermw.RequestLoggerFromContext(ctx); rlogger != nil { + rlogger.WithFields( + slog.F("workspace_name", resource.Name), + slog.F("agent_name", agent.Name), + ) + } + next.ServeHTTP(rw, r.WithContext(ctx)) }) } diff --git a/coderd/httpmw/workspaceparam.go b/coderd/httpmw/workspaceparam.go index 21e8dcfd62863..0c4e4f77354fc 100644 --- a/coderd/httpmw/workspaceparam.go +++ b/coderd/httpmw/workspaceparam.go @@ -9,8 +9,11 @@ import ( "github.com/go-chi/chi/v5" "github.com/google/uuid" + "cdr.dev/slog" + "github.com/coder/coder/v2/coderd/database" "github.com/coder/coder/v2/coderd/httpapi" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/codersdk" ) @@ -48,6 +51,11 @@ func ExtractWorkspaceParam(db database.Store) func(http.Handler) http.Handler { } ctx = context.WithValue(ctx, workspaceParamContextKey{}, workspace) + + if rlogger := loggermw.RequestLoggerFromContext(ctx); rlogger != nil { + rlogger.WithFields(slog.F("workspace_name", workspace.Name)) + } + next.ServeHTTP(rw, r.WithContext(ctx)) }) } @@ -154,6 +162,13 @@ func ExtractWorkspaceAndAgentParam(db database.Store) func(http.Handler) http.Ha ctx = context.WithValue(ctx, workspaceParamContextKey{}, workspace) ctx = context.WithValue(ctx, workspaceAgentParamContextKey{}, agent) + + if rlogger := loggermw.RequestLoggerFromContext(ctx); rlogger != nil { + rlogger.WithFields( + slog.F("workspace_name", workspace.Name), + slog.F("agent_name", agent.Name), + ) + } next.ServeHTTP(rw, r.WithContext(ctx)) }) } diff --git a/coderd/inboxnotifications.go b/coderd/inboxnotifications.go index ea20c60de3cce..bc357bf2e35f2 100644 --- a/coderd/inboxnotifications.go +++ b/coderd/inboxnotifications.go @@ -16,6 +16,7 @@ import ( "github.com/coder/coder/v2/coderd/database/dbtime" "github.com/coder/coder/v2/coderd/httpapi" "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/notifications" "github.com/coder/coder/v2/coderd/pubsub" markdown "github.com/coder/coder/v2/coderd/render" @@ -220,7 +221,7 @@ func (api *API) watchInboxNotifications(rw http.ResponseWriter, r *http.Request) defer encoder.Close(websocket.StatusNormalClosure) // Log the request immediately instead of after it completes. - httpmw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) + loggermw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) for { select { diff --git a/coderd/provisionerjobs.go b/coderd/provisionerjobs.go index 335643390796f..6d75227a14ccd 100644 --- a/coderd/provisionerjobs.go +++ b/coderd/provisionerjobs.go @@ -20,6 +20,7 @@ import ( "github.com/coder/coder/v2/coderd/database/pubsub" "github.com/coder/coder/v2/coderd/httpapi" "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/rbac" "github.com/coder/coder/v2/coderd/rbac/policy" "github.com/coder/coder/v2/coderd/util/slice" @@ -555,7 +556,7 @@ func (f *logFollower) follow() { } // Log the request immediately instead of after it completes. - httpmw.RequestLoggerFromContext(f.ctx).WriteLog(f.ctx, http.StatusAccepted) + loggermw.RequestLoggerFromContext(f.ctx).WriteLog(f.ctx, http.StatusAccepted) // no need to wait if the job is done if f.complete { diff --git a/coderd/provisionerjobs_internal_test.go b/coderd/provisionerjobs_internal_test.go index c2c0a60c75ba0..f3bc2eb1dea99 100644 --- a/coderd/provisionerjobs_internal_test.go +++ b/coderd/provisionerjobs_internal_test.go @@ -19,8 +19,8 @@ import ( "github.com/coder/coder/v2/coderd/database/dbmock" "github.com/coder/coder/v2/coderd/database/dbtime" "github.com/coder/coder/v2/coderd/database/pubsub" - "github.com/coder/coder/v2/coderd/httpmw" - "github.com/coder/coder/v2/coderd/httpmw/loggermock" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw/loggermock" "github.com/coder/coder/v2/codersdk" "github.com/coder/coder/v2/provisionersdk" "github.com/coder/coder/v2/testutil" @@ -309,7 +309,7 @@ func Test_logFollower_EndOfLogs(t *testing.T) { mockLogger := loggermock.NewMockRequestLogger(ctrl) mockLogger.EXPECT().WriteLog(gomock.Any(), http.StatusAccepted).Times(1) - ctx = httpmw.WithRequestLogger(ctx, mockLogger) + ctx = loggermw.WithRequestLogger(ctx, mockLogger) // we need an HTTP server to get a websocket srv := httptest.NewServer(http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { diff --git a/coderd/rbac/authz.go b/coderd/rbac/authz.go index aaba7d6eae3af..02268e052d2e2 100644 --- a/coderd/rbac/authz.go +++ b/coderd/rbac/authz.go @@ -57,6 +57,23 @@ func hashAuthorizeCall(actor Subject, action policy.Action, object Object) [32]b return hashOut } +// SubjectType represents the type of subject in the RBAC system. +type SubjectType string + +const ( + SubjectTypeUser SubjectType = "user" + SubjectTypeProvisionerd SubjectType = "provisionerd" + SubjectTypeAutostart SubjectType = "autostart" + SubjectTypeHangDetector SubjectType = "hang_detector" + SubjectTypeResourceMonitor SubjectType = "resource_monitor" + SubjectTypeCryptoKeyRotator SubjectType = "crypto_key_rotator" + SubjectTypeCryptoKeyReader SubjectType = "crypto_key_reader" + SubjectTypePrebuildsOrchestrator SubjectType = "prebuilds_orchestrator" + SubjectTypeSystemReadProvisionerDaemons SubjectType = "system_read_provisioner_daemons" + SubjectTypeSystemRestricted SubjectType = "system_restricted" + SubjectTypeNotifier SubjectType = "notifier" +) + // Subject is a struct that contains all the elements of a subject in an rbac // authorize. type Subject struct { @@ -66,6 +83,14 @@ type Subject struct { // external workspace proxy or other service type actor. FriendlyName string + // Email is entirely optional and is used for logging and debugging + // It is not used in any functional way. + Email string + + // Type indicates what kind of subject this is (user, system, provisioner, etc.) + // It is not used in any functional way, only for logging. + Type SubjectType + ID string Roles ExpandableRoles Groups []string diff --git a/coderd/workspaceagents.go b/coderd/workspaceagents.go index 9cb891ee7a5c8..5bfefdfda2a3e 100644 --- a/coderd/workspaceagents.go +++ b/coderd/workspaceagents.go @@ -33,6 +33,7 @@ import ( "github.com/coder/coder/v2/coderd/externalauth" "github.com/coder/coder/v2/coderd/httpapi" "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/jwtutils" "github.com/coder/coder/v2/coderd/rbac" "github.com/coder/coder/v2/coderd/rbac/policy" @@ -556,7 +557,7 @@ func (api *API) workspaceAgentLogs(rw http.ResponseWriter, r *http.Request) { defer t.Stop() // Log the request immediately instead of after it completes. - httpmw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) + loggermw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) go func() { defer func() { @@ -932,7 +933,7 @@ func (api *API) derpMapUpdates(rw http.ResponseWriter, r *http.Request) { defer encoder.Close(websocket.StatusGoingAway) // Log the request immediately instead of after it completes. - httpmw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) + loggermw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) go func(ctx context.Context) { // TODO(mafredri): Is this too frequent? Use separate ping disconnect timeout? @@ -1310,7 +1311,7 @@ func (api *API) watchWorkspaceAgentMetadata(rw http.ResponseWriter, r *http.Requ defer sendTicker.Stop() // Log the request immediately instead of after it completes. - httpmw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) + loggermw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) // Send initial metadata. sendMetadata() diff --git a/enterprise/coderd/provisionerdaemons.go b/enterprise/coderd/provisionerdaemons.go index 15e3c3901ade3..6ffa15851214d 100644 --- a/enterprise/coderd/provisionerdaemons.go +++ b/enterprise/coderd/provisionerdaemons.go @@ -24,6 +24,7 @@ import ( "github.com/coder/coder/v2/coderd/database/dbtime" "github.com/coder/coder/v2/coderd/httpapi" "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/provisionerdserver" "github.com/coder/coder/v2/coderd/rbac" "github.com/coder/coder/v2/coderd/rbac/policy" @@ -378,7 +379,7 @@ func (api *API) provisionerDaemonServe(rw http.ResponseWriter, r *http.Request) }) // Log the request immediately instead of after it completes. - httpmw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) + loggermw.RequestLoggerFromContext(ctx).WriteLog(ctx, http.StatusAccepted) err = server.Serve(ctx, session) srvCancel() diff --git a/enterprise/wsproxy/wsproxy.go b/enterprise/wsproxy/wsproxy.go index 9108283513e4f..0b434c767f53a 100644 --- a/enterprise/wsproxy/wsproxy.go +++ b/enterprise/wsproxy/wsproxy.go @@ -32,6 +32,7 @@ import ( "github.com/coder/coder/v2/coderd/cryptokeys" "github.com/coder/coder/v2/coderd/httpapi" "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/tracing" "github.com/coder/coder/v2/coderd/workspaceapps" "github.com/coder/coder/v2/codersdk" @@ -336,7 +337,7 @@ func New(ctx context.Context, opts *Options) (*Server, error) { tracing.Middleware(s.TracerProvider), httpmw.AttachRequestID, httpmw.ExtractRealIP(s.Options.RealIPConfig), - httpmw.Logger(s.Logger), + loggermw.Logger(s.Logger), prometheusMW, corsMW, diff --git a/tailnet/test/integration/integration.go b/tailnet/test/integration/integration.go index 08c66b515cd53..1190a3aa98b0d 100644 --- a/tailnet/test/integration/integration.go +++ b/tailnet/test/integration/integration.go @@ -33,7 +33,7 @@ import ( "cdr.dev/slog" "github.com/coder/coder/v2/coderd/httpapi" - "github.com/coder/coder/v2/coderd/httpmw" + "github.com/coder/coder/v2/coderd/httpmw/loggermw" "github.com/coder/coder/v2/coderd/tracing" "github.com/coder/coder/v2/codersdk" "github.com/coder/coder/v2/tailnet" @@ -200,7 +200,7 @@ func (o SimpleServerOptions) Router(t *testing.T, logger slog.Logger) *chi.Mux { }) }, tracing.StatusWriterMiddleware, - httpmw.Logger(logger), + loggermw.Logger(logger), ) r.Route("/derp", func(r chi.Router) {