Skip to content
Merged
Show file tree
Hide file tree
Changes from all 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
8 changes: 8 additions & 0 deletions agent/api.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,12 +7,20 @@ import (
"github.com/google/uuid"

"github.com/coder/coder/v2/coderd/httpapi"
"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/codersdk/workspacesdk"
"github.com/coder/coder/v2/httpmw"
)

func (a *agent) apiHandler() http.Handler {
r := chi.NewRouter()
r.Use(
httpmw.Recover(a.logger),
tracing.StatusWriterMiddleware,
loggermw.Logger(a.logger),
)
r.Get("/", func(rw http.ResponseWriter, r *http.Request) {
httpapi.Write(r.Context(), rw, http.StatusOK, codersdk.Response{
Message: "Hello from the agent!",
Expand Down
3 changes: 2 additions & 1 deletion coderd/coderd.go
Original file line number Diff line number Diff line change
Expand Up @@ -99,6 +99,7 @@ import (
"github.com/coder/coder/v2/coderd/workspacestats"
"github.com/coder/coder/v2/codersdk"
"github.com/coder/coder/v2/codersdk/healthsdk"
sharedhttpmw "github.com/coder/coder/v2/httpmw"
"github.com/coder/coder/v2/provisionersdk"
"github.com/coder/coder/v2/site"
"github.com/coder/coder/v2/tailnet"
Expand Down Expand Up @@ -861,7 +862,7 @@ func New(options *Options) *API {
prometheusMW := httpmw.Prometheus(options.PrometheusRegistry)

r.Use(
httpmw.Recover(api.Logger),
sharedhttpmw.Recover(api.Logger),
httpmw.WithProfilingLabels,
tracing.StatusWriterMiddleware,
tracing.Middleware(api.TracerProvider),
Expand Down
87 changes: 9 additions & 78 deletions coderd/httpmw/loggermw/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,19 +7,17 @@ import (
"net/url"
"strconv"
"strings"
"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"
)

var (
safeParams = []string{"page", "limit", "offset"}
safeParams = []string{"page", "limit", "offset", "path"}
countParams = []string{"ids", "template_ids"}
)

Expand Down Expand Up @@ -124,95 +122,28 @@ 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 {
log slog.Logger
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{}

func NewRequestLogger(log slog.Logger, message string, start time.Time) RequestLogger {
return &SlogRequestLogger{
log: log,
written: false,
message: message,
start: start,
actors: make(map[rbac.SubjectType]rbac.Subject),
}
log slog.Logger
written bool
message string
start time.Time
addFields func()
}

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.SubjectTypeJobReaper,
rbac.SubjectTypeNotifier,
rbac.SubjectTypePrebuildsOrchestrator,
rbac.SubjectTypeSubAgentAPI,
rbac.SubjectTypeProvisionerd,
rbac.SubjectTypeResourceMonitor,
rbac.SubjectTypeSystemReadProvisionerDaemons,
rbac.SubjectTypeSystemRestricted,
}

func (c *SlogRequestLogger) WriteLog(ctx context.Context, status int) {
if c.written {
return
}
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()
if c.addFields != nil {
c.addFields()
}

logger := c.log.With(
slog.F("took", end.Sub(c.start)),
Expand Down
88 changes: 88 additions & 0 deletions coderd/httpmw/loggermw/logger_full.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,88 @@
//go:build !slim

package loggermw

import (
"context"
"sync"
"time"

"cdr.dev/slog"
"github.com/coder/coder/v2/coderd/rbac"
)

type RequestLogger interface {
WithFields(fields ...slog.Field)
WriteLog(ctx context.Context, status int)
WithAuthContext(actor rbac.Subject)
}

type RbacSlogRequestLogger struct {
SlogRequestLogger
// Protects actors map for concurrent writes.
mu sync.RWMutex
actors map[rbac.SubjectType]rbac.Subject
}

var _ RequestLogger = &RbacSlogRequestLogger{}

func NewRequestLogger(log slog.Logger, message string, start time.Time) RequestLogger {
rlogger := &RbacSlogRequestLogger{
SlogRequestLogger: SlogRequestLogger{
log: log,
written: false,
message: message,
start: start,
},
actors: make(map[rbac.SubjectType]rbac.Subject),
}
rlogger.addFields = rlogger.addAuthContextFields
return rlogger
}

func (c *RbacSlogRequestLogger) WithAuthContext(actor rbac.Subject) {
c.mu.Lock()
defer c.mu.Unlock()
c.actors[actor.Type] = actor
}

var actorLogOrder = []rbac.SubjectType{
rbac.SubjectTypeAutostart,
rbac.SubjectTypeCryptoKeyReader,
rbac.SubjectTypeCryptoKeyRotator,
rbac.SubjectTypeJobReaper,
rbac.SubjectTypeNotifier,
rbac.SubjectTypePrebuildsOrchestrator,
rbac.SubjectTypeSubAgentAPI,
rbac.SubjectTypeProvisionerd,
rbac.SubjectTypeResourceMonitor,
rbac.SubjectTypeSystemReadProvisionerDaemons,
rbac.SubjectTypeSystemRestricted,
}

func (c *RbacSlogRequestLogger) 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
}
}
}
26 changes: 26 additions & 0 deletions coderd/httpmw/loggermw/logger_internal_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ import (
"github.com/stretchr/testify/require"

"cdr.dev/slog"
"github.com/coder/coder/v2/coderd/rbac"
"github.com/coder/coder/v2/coderd/tracing"
"github.com/coder/coder/v2/testutil"
"github.com/coder/websocket"
Expand Down Expand Up @@ -363,6 +364,31 @@ func TestSafeQueryParams(t *testing.T) {
}
}

func TestRequestLogger_AuthContext(t *testing.T) {
t.Parallel()
ctx := context.Background()

sink := &fakeSink{}
logger := slog.Make(sink)
logger = logger.Leveled(slog.LevelDebug)
logCtx := NewRequestLogger(logger, "GET", time.Now())

logCtx.WithAuthContext(rbac.Subject{
ID: "test-user-id",
FriendlyName: "test name",
Email: "test@coder.com",
Type: rbac.SubjectTypeUser,
})

logCtx.WriteLog(ctx, http.StatusOK)

require.Len(t, sink.entries, 1, "log was written twice")
require.Equal(t, sink.entries[0].Message, "GET")
require.Equal(t, sink.entries[0].Fields[0].Value, "test-user-id")
require.Equal(t, sink.entries[0].Fields[1].Value, "test name")
require.Equal(t, sink.entries[0].Fields[2].Value, "test@coder.com")
}

type fakeSink struct {
entries []slog.SinkEntry
newEntries chan slog.SinkEntry
Expand Down
26 changes: 26 additions & 0 deletions coderd/httpmw/loggermw/logger_slim.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
//go:build slim

package loggermw

import (
"context"
"time"

"cdr.dev/slog"
)

type RequestLogger interface {
WithFields(fields ...slog.Field)
WriteLog(ctx context.Context, status int)
}

var _ RequestLogger = &SlogRequestLogger{}

func NewRequestLogger(log slog.Logger, message string, start time.Time) RequestLogger {
return &SlogRequestLogger{
log: log,
written: false,
message: message,
start: start,
}
}
3 changes: 2 additions & 1 deletion enterprise/wsproxy/wsproxy.go
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ import (
"github.com/coder/coder/v2/enterprise/derpmesh"
"github.com/coder/coder/v2/enterprise/replicasync"
"github.com/coder/coder/v2/enterprise/wsproxy/wsproxysdk"
sharedhttpmw "github.com/coder/coder/v2/httpmw"
"github.com/coder/coder/v2/site"
"github.com/coder/coder/v2/tailnet"
)
Expand Down Expand Up @@ -328,7 +329,7 @@ func New(ctx context.Context, opts *Options) (*Server, error) {
// Persistent middlewares to all routes
r.Use(
// TODO: @emyrk Should we standardize these in some other package?
httpmw.Recover(s.Logger),
sharedhttpmw.Recover(s.Logger),
httpmw.WithProfilingLabels,
tracing.StatusWriterMiddleware,
tracing.Middleware(s.TracerProvider),
Expand Down
File renamed without changes.
2 changes: 1 addition & 1 deletion coderd/httpmw/recover_test.go → httpmw/recover_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,8 @@ import (

"github.com/stretchr/testify/require"

"github.com/coder/coder/v2/coderd/httpmw"
"github.com/coder/coder/v2/coderd/tracing"
"github.com/coder/coder/v2/httpmw"
"github.com/coder/coder/v2/testutil"
)

Expand Down
Loading