Skip to content
Closed
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
56 changes: 50 additions & 6 deletions cmd/cachewd/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ import (
"go.opentelemetry.io/otel"
"go.opentelemetry.io/otel/attribute"

"github.com/block/cachew/internal/accesslog"
"github.com/block/cachew/internal/cache"
"github.com/block/cachew/internal/config"
"github.com/block/cachew/internal/gitclone"
Expand Down Expand Up @@ -54,6 +55,7 @@ type GlobalConfig struct {
MetricsConfig metrics.Config `hcl:"metrics,block"`
GitCloneConfig gitclone.Config `hcl:"git-clone,block"`
S3Config s3client.Config `hcl:"s3,block,optional"`
AccessLogConfig accesslog.Config `hcl:"access-log,block,optional"`
GithubAppConfigs []githubapp.Config `hcl:"github-app,block,optional"`
OPAConfig opa.Config `hcl:"opa,block"`
}
Expand Down Expand Up @@ -141,29 +143,28 @@ func main() {
mux, err := newMux(ctx, &shuttingDown, cr, mr, sr, providersConfigHCL, envars)
fatalIfError(ctx, logger, err, "Failed to load config")

metricsClient, err := metrics.New(ctx, globalConfig.MetricsConfig)
fatalIfError(ctx, logger, err, "Failed to create metrics client")
metricsClient := startMetrics(ctx, logger, globalConfig.MetricsConfig)
defer func() {
if err := metricsClient.Close(); err != nil {
logger.ErrorContext(ctx, "Failed to close metrics client", "error", err)
}
}()

if err := metricsClient.ServeMetrics(ctx); err != nil {
fatalIfError(ctx, logger, err, "Failed to start metrics server")
}

runOPATests(ctx, logger, globalConfig.OPAConfig)

logger.InfoContext(ctx, "Starting cachewd", "bind", globalConfig.Bind)

accessLogWriter := newAccessLogWriter(ctx, logger, globalConfig.AccessLogConfig, s3ClientProvider)

server, err := newServer(
ctx,
mux,
globalConfig.Bind,
globalConfig.MetricsConfig,
globalConfig.OPAConfig,
globalConfig.LoggingConfig,
globalConfig.AccessLogConfig,
accessLogWriter,
)
fatalIfError(ctx, logger, err, "Failed to create server")

Expand All @@ -186,10 +187,46 @@ func main() {

gracefulShutdown(ctx, logger, server, &shuttingDown, globalConfig.ShutdownReadinessDelay, globalConfig.ShutdownTimeout)

closeAccessLogWriter(ctx, logger, accessLogWriter)

cancelScheduler()
drainScheduler(ctx, logger, schedulerProvider)
}

// startMetrics creates the metrics client and starts the metrics server,
// exiting the process on failure.
func startMetrics(ctx context.Context, logger *slog.Logger, config metrics.Config) *metrics.Client {
metricsClient, err := metrics.New(ctx, config)
fatalIfError(ctx, logger, err, "Failed to create metrics client")
if err := metricsClient.ServeMetrics(ctx); err != nil {
fatalIfError(ctx, logger, err, "Failed to start metrics server")
}
return metricsClient
}

// newAccessLogWriter returns nil when access log export is not configured,
// exiting the process on invalid configuration.
func newAccessLogWriter(ctx context.Context, logger *slog.Logger, config accesslog.Config, provider s3client.ClientProvider) *accesslog.Writer {
if config.Bucket == "" {
return nil
}
fatalIfError(ctx, logger, config.Validate(), "Invalid access log config")
return accesslog.NewWriter(ctx, config, provider)
Comment on lines +213 to +214

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

P1 Badge Return access-log initialization errors to main

When access-log validation fails, this factory logs and terminates the process internally through fatalIfError instead of returning the error, preventing its caller from controlling reporting or cleanup. Return an error from the helper and handle it in main, as required by the repository's error-handling convention.

AGENTS.md reference: AGENTS.md:L24-L25

Useful? React with 👍 / 👎.

}

const accessLogCloseTimeout = 30 * time.Second

func closeAccessLogWriter(ctx context.Context, logger *slog.Logger, writer *accesslog.Writer) {
if writer == nil {
return
}
closeCtx, cancel := context.WithTimeout(context.WithoutCancel(ctx), accessLogCloseTimeout)
defer cancel()
if err := writer.Close(closeCtx); err != nil {
logger.ErrorContext(ctx, "Failed to flush access log writer", "error", err)
}
}

// gracefulShutdown fails readiness, waits readinessDelay for load balancers
// to drain, then runs http.Server.Shutdown bounded by shutdownTimeout.
func gracefulShutdown(
Expand Down Expand Up @@ -380,6 +417,8 @@ func newServer(
metricsConfig metrics.Config,
opaConfig opa.Config,
logConfig logging.Config,
accessLogConfig accesslog.Config,
accessLogWriter *accesslog.Writer,
) (*http.Server, error) {
var handler http.Handler = http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
labeler, _ := otelhttp.LabelerFromContext(r.Context())
Expand All @@ -392,6 +431,11 @@ func newServer(
return nil, errors.Errorf("initialise OPA middleware: %w", err)
}

// Wrap outside OPA so denied requests are captured too.
if accessLogWriter != nil {
handler = accesslog.Middleware(handler, accessLogWriter, accessLogConfig)
}

// Add standard otelhttp middleware
handler = otelhttp.NewMiddleware(metricsConfig.ServiceName,
otelhttp.WithMeterProvider(otel.GetMeterProvider()),
Expand Down
134 changes: 134 additions & 0 deletions internal/accesslog/accesslog.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,134 @@
// Package accesslog exports structured HTTP access log events to S3 as
// batched JSONL objects (gzip-compressed by default), suitable for ingestion
// by log analysis and security monitoring pipelines.
package accesslog

import (
"net/http"
"time"

"github.com/alecthomas/errors"
)

// Compression modes for exported objects.
const (
CompressionGzip = "gzip"
CompressionNone = "none"
)

// Config configures access log export to S3. Export is enabled when Bucket is
// non-empty. Connection parameters (endpoint, region, credentials) come from
// the global s3 block.
type Config struct {
Bucket string `hcl:"bucket" help:"S3 bucket to export access log events to."`
Prefix string `hcl:"prefix,optional" default:"access-logs" help:"Object key prefix for exported batches."`
FlushInterval time.Duration `hcl:"flush-interval,optional" default:"1m" help:"How often buffered events are flushed to S3."`
MaxBufferedEvents int `hcl:"max-buffered-events,optional" default:"65536" help:"Maximum events held in memory; new events are dropped when the buffer is full."`
Compression string `hcl:"compression,optional" default:"gzip" help:"Compression for exported objects: gzip or none."`
Headers map[string]string `hcl:"headers,optional" help:"Record these inbound request headers as the given event field."`
}

// Validate checks the configuration for invalid values.
func (c Config) Validate() error {
if c.FlushInterval <= 0 {

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

P1 Badge Reject non-positive access-log buffer capacities

When max-buffered-events is explicitly configured as zero or a negative value, validation succeeds, but Record then satisfies len(w.events) >= w.config.MaxBufferedEvents for every request and silently drops the entire access log stream. Reject non-positive capacities during startup rather than accepting a configuration that can never export an event.

Useful? React with 👍 / 👎.

return errors.Errorf("invalid access log flush-interval %s: must be positive", c.FlushInterval)
}
switch c.Compression {
case "", CompressionGzip, CompressionNone:
return nil
Comment thread
worstell marked this conversation as resolved.
default:
return errors.Errorf("invalid access log compression %q: must be %q or %q", c.Compression, CompressionGzip, CompressionNone)
}
}

// Event is a single access log record. It is serialised as one JSON object
// per line (JSONL).
type Event struct {
Timestamp time.Time `json:"timestamp"`
Method string `json:"method"`
Path string `json:"path"`
Query string `json:"query,omitempty"`
Status int `json:"status"`
BytesSent int64 `json:"bytes_sent"`
DurationMS float64 `json:"duration_ms"`
RemoteAddr string `json:"remote_addr"`
Host string `json:"host,omitempty"`
UserAgent string `json:"user_agent,omitempty"`
Headers map[string]string `json:"headers,omitempty"`
}

// Recorder accepts access log events. Implemented by *Writer.
type Recorder interface {
Record(event Event)
}

// Middleware records one Event per request to the given Recorder.
func Middleware(next http.Handler, recorder Recorder, config Config) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
rec := &responseRecorder{ResponseWriter: w}
start := time.Now()
next.ServeHTTP(rec, r)

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

P2 Badge Record access events when downstream handlers panic

If an OPA or strategy handler panics, control unwinds past this call and never reaches recorder.Record, while net/http recovers outside this middleware; consequently the failure produces no access event despite the middleware's one-event-per-request contract. Arrange event recording in deferred cleanup while preserving the panic so these especially important failed requests remain observable.

Useful? React with 👍 / 👎.


event := Event{
Timestamp: start.UTC(),
Method: r.Method,
Path: r.URL.Path,
Query: r.URL.RawQuery,
Status: rec.statusCode(),
BytesSent: rec.bytes,
DurationMS: float64(time.Since(start)) / float64(time.Millisecond),
RemoteAddr: r.RemoteAddr,
Host: r.Host,
UserAgent: r.UserAgent(),
}
for header, field := range config.Headers {
if v := r.Header.Get(header); v != "" {
if event.Headers == nil {
event.Headers = map[string]string{}
}
event.Headers[field] = v
}
}
recorder.Record(event)
})
}

type responseRecorder struct {
http.ResponseWriter
status int
bytes int64
}

func (r *responseRecorder) WriteHeader(status int) {
if r.status == 0 {
r.status = status
}
r.ResponseWriter.WriteHeader(status)
}

func (r *responseRecorder) Write(b []byte) (int, error) {
if r.status == 0 {
r.status = http.StatusOK
}
n, err := r.ResponseWriter.Write(b)
r.bytes += int64(n)
return n, err //nolint:wrapcheck
}

// Flush is implemented explicitly because streaming handlers type-assert
// http.Flusher directly on the ResponseWriter they receive.
func (r *responseRecorder) Flush() {
if f, ok := r.ResponseWriter.(http.Flusher); ok {
f.Flush()
}
}

// Unwrap supports http.ResponseController.
func (r *responseRecorder) Unwrap() http.ResponseWriter { return r.ResponseWriter }

func (r *responseRecorder) statusCode() int {
if r.status == 0 {
return http.StatusOK
}
return r.status
}
54 changes: 54 additions & 0 deletions internal/accesslog/accesslog_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,54 @@
package accesslog_test

import (
"net/http"
"net/http/httptest"
"testing"

"github.com/alecthomas/assert/v2"

"github.com/block/cachew/internal/accesslog"
)

type recorder struct {
events []accesslog.Event
}

func (r *recorder) Record(event accesslog.Event) { r.events = append(r.events, event) }

func TestMiddleware(t *testing.T) {
rec := &recorder{}
handler := accesslog.Middleware(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusTeapot)
_, _ = w.Write([]byte("hello")) //nolint:errcheck
}), rec, accesslog.Config{Headers: map[string]string{"X-Client-Id": "client_id"}})

req := httptest.NewRequest(http.MethodGet, "/git/github.com/org/repo?service=git-upload-pack", nil)
req.Header.Set("X-Client-Id", "abc-123")
req.Header.Set("User-Agent", "git/2.44.0")
handler.ServeHTTP(httptest.NewRecorder(), req)

assert.Equal(t, 1, len(rec.events))
event := rec.events[0]
assert.Equal(t, http.MethodGet, event.Method)
assert.Equal(t, "/git/github.com/org/repo", event.Path)
assert.Equal(t, "service=git-upload-pack", event.Query)
assert.Equal(t, http.StatusTeapot, event.Status)
assert.Equal(t, 5, int(event.BytesSent))
assert.Equal(t, "git/2.44.0", event.UserAgent)
assert.Equal(t, map[string]string{"client_id": "abc-123"}, event.Headers)
assert.False(t, event.Timestamp.IsZero())
}

func TestMiddlewareImplicitOK(t *testing.T) {
rec := &recorder{}
handler := accesslog.Middleware(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
_, _ = w.Write([]byte("ok")) //nolint:errcheck
}), rec, accesslog.Config{})

handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest(http.MethodGet, "/", nil))

assert.Equal(t, 1, len(rec.events))
assert.Equal(t, http.StatusOK, rec.events[0].Status)
assert.Zero(t, rec.events[0].Headers)
}
Loading