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
13 changes: 12 additions & 1 deletion internal/comparison/comparator.go
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,12 @@ func (c *Comparator) MaxResponseBytes() int {
return c.maxResponseBytes
}

// Ignored reports whether the request matches an endpoint declared ignored, so
// callers can log its noisy health-check traffic at debug level.
func (c *Comparator) Ignored(requestMethod, requestPath string) bool {
return c.scripts.ignored(requestMethod, requestPath)
}

// Configure activates the comparator against the wire descriptors.
func (c *Comparator) Configure(ctx context.Context, set *descriptorpb.FileDescriptorSet) error {
configured, err := c.scripts.prepare(ctx, set)
Expand All @@ -60,6 +66,7 @@ func (c *Comparator) Compare(
reference Response,
candidate Response,
) (result Result) {
ignored := c.scripts.ignored(requestMethod, requestPath)
defer func() {
attributes := []any{"event", logger.EventCorrelation, "path", requestPath, "outcome", result.Outcome()}
differences := result.Differences()
Expand All @@ -69,7 +76,11 @@ func (c *Comparator) Compare(
if result.Reason() != "" {
attributes = append(attributes, "reason", result.Reason())
}
c.log.InfoContext(ctx, "Response comparison completed", attributes...)
level := slog.LevelInfo
if ignored {
level = slog.LevelDebug
}
c.log.Log(ctx, level, "Response comparison completed", attributes...)
}()
if excludedRequestPath(requestPath) {
return Resultf(Skipped, "gRPC namespace is excluded from response comparison")
Expand Down
15 changes: 15 additions & 0 deletions internal/comparison/comparator_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -589,6 +589,21 @@ func TestIgnoredEndpointSkipsComparison(t *testing.T) {
assert.Equal(t, comparison.Skipped, result.Outcome())
}

func TestIgnoredEndpointLogsAtDebug(t *testing.T) {
var output bytes.Buffer
log := slog.New(slog.NewJSONHandler(&output, &slog.HandlerOptions{Level: slog.LevelDebug}))
config := newConfig(t, map[string]string{"status.ts": module(`spectre.ingress.ignore("http", "GET /_status");`)})
comparator, err := comparison.New(t.Context(), config, log)
assert.NoError(t, err)
assert.NoError(t, comparator.Configure(t.Context(), descriptorSet()))
response := httpJSONResponse(http.StatusBadGateway, "text/html", `<html>502 Bad Gateway</html>`)

result := comparator.Compare(t.Context(), http.MethodGet, "/_status", "", response, response)

assert.Equal(t, comparison.Skipped, result.Outcome())
assert.Contains(t, output.String(), `"level":"DEBUG","msg":"Response comparison completed","event":"correlation","path":"/_status","outcome":"skipped","reason":"endpoint \"GET /_status\" is ignored"`)
}

func TestRejectsHTTPJSONWithUnknownFields(t *testing.T) {
comparator := newScriptsComparator(t, map[string]string{"weather.ts": forecastScript("")})
reference := httpJSONResponse(http.StatusOK, "application/json", `{"stable":"same","roles":[],"users":[],"count":"0","labels":{}}`)
Expand Down
7 changes: 7 additions & 0 deletions internal/comparison/scripts.go
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,13 @@ func (s *scriptSet) resolve(configured *configuredScripts, method, host, path, c
return root, identity, selected, wildcards, newEmptyResult()
}

// ignored reports whether the request matches an endpoint declared ignored, so its
// traffic is skipped during comparison and logged at debug level.
func (s *scriptSet) ignored(requestMethod, requestPath string) bool {
endpoint, _, matched := s.routes.Match(requestMethod, "", requestPath)
return matched && endpoint.Ignore()
}

// normalise gives each payload a fresh evaluator, so script state cannot carry
// between payloads and a payload's normalised form depends only on its content.
func (s *scriptSet) normalise(ctx context.Context, configured *configuredScripts, root *schema.Type,
Expand Down
4 changes: 3 additions & 1 deletion internal/ingress/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@ type DescriptorLoader interface {
// ResponseComparator compares paired backend responses against a shared schema.
type ResponseComparator interface {
MaxResponseBytes() int
Ignored(requestMethod, requestPath string) bool
Configure(ctx context.Context, set *descriptorpb.FileDescriptorSet) error
Compare(
ctx context.Context,
Expand Down Expand Up @@ -126,7 +127,8 @@ func New(
comparator: comparator,
candidates: proxy.NewCandidates(config.CandidateMaxInFlight, log),
}
requestHandler := logging.New(http.HandlerFunc(handler.serveProxy), log, logger.EventIngressReceived)
requestHandler := logging.NewDemoting(http.HandlerFunc(handler.serveProxy), log, logger.EventIngressReceived,
func(request *http.Request) bool { return comparator.Ignored(request.Method, request.URL.Path) })
handler.health = health.New(requestHandler)
return handler, nil
}
Expand Down
8 changes: 8 additions & 0 deletions internal/ingress/handler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1143,6 +1143,7 @@ type responseComparator struct {
comparison.Response,
) comparison.Result
configure Option[func(set *descriptorpb.FileDescriptorSet)]
ignored Option[func(requestMethod, requestPath string) bool]
}

func newResponseComparator(compare func(
Expand All @@ -1160,6 +1161,13 @@ func (c *responseComparator) MaxResponseBytes() int {
return 1024
}

func (c *responseComparator) Ignored(requestMethod, requestPath string) bool {
if ignored, ok := c.ignored.Get(); ok {
return ignored(requestMethod, requestPath)
}
return false
}

func (c *responseComparator) Configure(ctx context.Context, set *descriptorpb.FileDescriptorSet) error {
_ = ctx
if configure, ok := c.configure.Get(); ok {
Expand Down
19 changes: 17 additions & 2 deletions internal/middleware/logging/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,19 +7,30 @@ import (
"time"

"github.com/alecthomas/errors"
. "github.com/alecthomas/types/optional"
)

// Demoter reports whether a request's log line should drop from info to debug level.
type Demoter func(request *http.Request) bool

// Handler logs each request after delegating it to the next handler.
type Handler struct {
next http.Handler
log *slog.Logger
event string
debug Option[Demoter]
}

// New constructs request logging middleware around the next handler. event names
// the SPECTRE event each request is logged under, e.g. "ingress_received".
func New(next http.Handler, log *slog.Logger, event string) *Handler {
return &Handler{next: next, log: log, event: event}
return &Handler{next: next, log: log, event: event, debug: None[Demoter]()}
}

// NewDemoting is like New but logs a request at debug instead of info when demote
// reports true, keeping low-value traffic such as health checks quiet by default.
func NewDemoting(next http.Handler, log *slog.Logger, event string, demote Demoter) *Handler {
return &Handler{next: next, log: log, event: event, debug: Some(demote)}
}

// ServeHTTP logs the event, method, path, response status, and elapsed time.
Expand All @@ -31,7 +42,11 @@ func (h *Handler) ServeHTTP(writer http.ResponseWriter, request *http.Request) {
if status == 0 {
status = http.StatusOK
}
h.log.InfoContext(request.Context(), "HTTP request",
level := slog.LevelInfo
if demote, ok := h.debug.Get(); ok && demote(request) {
level = slog.LevelDebug
}
h.log.Log(request.Context(), level, "HTTP request",
"event", h.event,
"method", request.Method,
"path", request.URL.Path,
Expand Down
30 changes: 30 additions & 0 deletions internal/middleware/logging/handler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,36 @@ func TestLogsRequests(t *testing.T) {
}
}

func TestDemotesMatchingRequests(t *testing.T) {
for _, test := range []struct {
name string
path string
level string
}{
{name: "Ignored", path: "/_status", level: "DEBUG"},
{name: "Compared", path: "/users", level: "INFO"},
} {
t.Run(test.name, func(t *testing.T) {
var output bytes.Buffer
log := slog.New(slog.NewJSONHandler(&output, &slog.HandlerOptions{Level: slog.LevelDebug}))
handler := logging.NewDemoting(http.HandlerFunc(func(writer http.ResponseWriter, _ *http.Request) {
_, err := writer.Write([]byte("ok"))
assert.NoError(t, err)
}), log, "ingress_received", func(request *http.Request) bool {
return request.URL.Path == "/_status"
})
handler.ServeHTTP(httptest.NewRecorder(), httptest.NewRequest(http.MethodGet, test.path, nil))

var record map[string]any
assert.NoError(t, json.Unmarshal(output.Bytes(), &record))
level, _ := record["level"].(string)
assert.Equal(t, test.level, level)
assert.Equal(t, "HTTP request", record["msg"])
assert.Equal(t, "ingress_received", record["event"])
})
}
}

func TestPreservesFlushing(t *testing.T) {
response := httptest.NewRecorder()
log := slog.New(slog.DiscardHandler)
Expand Down
Loading