From cafca3075b4efc1fcec851b36637f4c45d347578 Mon Sep 17 00:00:00 2001 From: Cursor Agent Date: Wed, 12 Aug 2026 07:04:07 +0000 Subject: [PATCH] fix: stop counting expected dependency failures as APM errors Classify Store API 429s, tenant shop 401/403, Sitespeed 503s, and soft SMTP failures so otelhttp/gomailer spans keep status codes as attributes with error.expected=true instead of status=Error. Real bugs and final hard failures still Error. Coordinates with shopmon.*.outcome metrics. Co-authored-by: Soner --- api/go.mod | 1 - api/go.sum | 2 - api/internal/catalog/sync/service.go | 7 +- api/internal/httputil/client.go | 20 ++- api/internal/mail/mail.go | 13 +- api/internal/mail/otel.go | 90 ++++++++++ api/internal/mail/smtp_expected.go | 35 ++++ api/internal/mail/smtp_expected_test.go | 39 ++++ api/internal/monitoring/scrape/service.go | 7 +- api/internal/monitoring/sitespeed/service.go | 50 +++++- api/internal/otelx/expected.go | 180 +++++++++++++++++++ api/internal/otelx/expected_test.go | 113 ++++++++++++ api/internal/otelx/http_transport.go | 82 +++++++++ api/internal/otelx/http_transport_test.go | 82 +++++++++ api/internal/shopware/client.go | 3 + api/internal/shopwareaccount/retry.go | 3 + 16 files changed, 703 insertions(+), 24 deletions(-) create mode 100644 api/internal/mail/otel.go create mode 100644 api/internal/mail/smtp_expected.go create mode 100644 api/internal/mail/smtp_expected_test.go create mode 100644 api/internal/otelx/expected.go create mode 100644 api/internal/otelx/expected_test.go create mode 100644 api/internal/otelx/http_transport.go create mode 100644 api/internal/otelx/http_transport_test.go diff --git a/api/go.mod b/api/go.mod index f91fea82..939088ba 100644 --- a/api/go.mod +++ b/api/go.mod @@ -26,7 +26,6 @@ require ( github.com/robfig/cron/v3 v3.0.1 github.com/russross/blackfriday/v2 v2.1.0 github.com/shyim/go-mailer v0.1.0 - github.com/shyim/go-mailer/middleware/otelmw v0.1.0 github.com/shyim/go-mailer/transport/smtp v0.1.0 github.com/shyim/go-queue v0.0.0-20260606124220-e2aa789807c9 github.com/shyim/go-version v0.0.0-20260602054622-2f4aa95a0358 diff --git a/api/go.sum b/api/go.sum index dfce6025..145ce3aa 100644 --- a/api/go.sum +++ b/api/go.sum @@ -258,8 +258,6 @@ github.com/shirou/gopsutil/v4 v4.26.5 h1:RPcBXkpz7kOj9PqGFQOlBPZHsyaPvPVQc098y9R github.com/shirou/gopsutil/v4 v4.26.5/go.mod h1:LZ6ewCSkBqUpvSOf+LsTGnRinC6iaNUNMGBtDkJBaLQ= github.com/shyim/go-mailer v0.1.0 h1:je50kIrHk2IAvVrz99pwZSNMIW+l9ZNGPwVPrSBt2s4= github.com/shyim/go-mailer v0.1.0/go.mod h1:XdMOEImXpUjCIGO+TPH3jELmIHAYLeprkkVaM1PjCXA= -github.com/shyim/go-mailer/middleware/otelmw v0.1.0 h1:4/YegdksPWXOA6ipSb8Ay3FyBVbE8fHHxIuxHjH9EO8= -github.com/shyim/go-mailer/middleware/otelmw v0.1.0/go.mod h1:eb0JR9ZEhOu2Kfopu0I4dtIzn0Pif5a9P8EXIC4hLLU= github.com/shyim/go-mailer/transport/sendmail v0.1.0 h1:OeV5Yq63ibUqByR9MXgqSoWWUbenf2fNJro+lon8QrA= github.com/shyim/go-mailer/transport/sendmail v0.1.0/go.mod h1:sajMdVzJifN0rejTZeCFaEOSsQQUyIygNTiWCmm0kJI= github.com/shyim/go-mailer/transport/smtp v0.1.0 h1:WIVDl2TZ+yGPT63kF+CgtP9R5RS0TY2yP+18XyW2Krs= diff --git a/api/internal/catalog/sync/service.go b/api/internal/catalog/sync/service.go index e8525aa9..7b6dad7d 100644 --- a/api/internal/catalog/sync/service.go +++ b/api/internal/catalog/sync/service.go @@ -11,12 +11,12 @@ import ( "github.com/friendsofshopware/shopmon/api/internal/config" "github.com/friendsofshopware/shopmon/api/internal/database/queries" "github.com/friendsofshopware/shopmon/api/internal/metrics" + "github.com/friendsofshopware/shopmon/api/internal/otelx" "github.com/friendsofshopware/shopmon/api/internal/shopwareaccount" "github.com/friendsofshopware/shopmon/api/internal/version" "github.com/jackc/pgx/v5/pgxpool" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/attribute" - "go.opentelemetry.io/otel/codes" "go.opentelemetry.io/otel/trace" ) @@ -146,8 +146,9 @@ func (h *Service) SyncNames(ctx context.Context, names []string, shopwareVersion recordOutcome := true defer func() { if err != nil { - span.RecordError(err) - span.SetStatus(codes.Error, err.Error()) + // 429 aborts are expected (job retries; shopmon.store_sync.outcome + // =rate_limited). Other failures remain hard span errors. + otelx.RecordDependency(span, err) } span.End() if !recordOutcome { diff --git a/api/internal/httputil/client.go b/api/internal/httputil/client.go index b227ee80..a01f2b08 100644 --- a/api/internal/httputil/client.go +++ b/api/internal/httputil/client.go @@ -11,6 +11,7 @@ import ( "sync" "time" + "github.com/friendsofshopware/shopmon/api/internal/otelx" "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" ) @@ -92,16 +93,25 @@ func (t *userAgentTransport) RoundTrip(req *http.Request) (*http.Response, error } // wrapTransport adds the Shopmon User-Agent and OpenTelemetry instrumentation. -// Order: application -> userAgent -> otelhttp -> base, so the User-Agent is set -// before tracing observes the request and still applies when a custom base is used. +// +// Order (outbound): +// +// application → userAgent → expectedStatus → otelhttp → spanCapture → base +// +// User-Agent is set before tracing observes the request. expectedStatus sits +// outside otelhttp so it can downgrade expected dependency statuses (429, 401, +// 503, …) from span status Error to Ok after otelhttp applies semconv rules; +// spanCapture (inside otelhttp) hands it the client span via context. func wrapTransport(base http.RoundTripper) http.RoundTripper { if base == nil { base = http.DefaultTransport } return &userAgentTransport{ - base: otelhttp.NewTransport( - base, - otelhttp.WithSpanNameFormatter(ClientSpanName), + base: otelx.WrapClientTransport( + otelhttp.NewTransport( + otelx.CaptureClientSpan(base), + otelhttp.WithSpanNameFormatter(ClientSpanName), + ), ), ua: UserAgentString(), } diff --git a/api/internal/mail/mail.go b/api/internal/mail/mail.go index ac770443..a43ec2e3 100644 --- a/api/internal/mail/mail.go +++ b/api/internal/mail/mail.go @@ -11,8 +11,6 @@ import ( "github.com/friendsofshopware/shopmon/api/internal/metrics" gomailer "github.com/shyim/go-mailer" - "github.com/shyim/go-mailer/middleware" - "github.com/shyim/go-mailer/middleware/otelmw" "github.com/shyim/go-mailer/transport" smtptransport "github.com/shyim/go-mailer/transport/smtp" ) @@ -86,13 +84,10 @@ func NewService(cfg Config) (*Service, error) { st.SetAllowPlaintextAuth(true) } - // Instrument each delivery attempt with an OpenTelemetry span and metrics. - // Passing nil providers makes otelmw fall back to the globals configured by - // the telemetry package; when telemetry is disabled those are no-ops, so the - // middleware degrades to a cheap pass-through. We wrap the leaf transport so - // every delivery attempt (including retries) gets its own span, and keep the - // leaf's closer so shutdown still QUITs the pooled connection. - tr := middleware.Wrap(leaf, otelmw.New(nil, nil)) + // Instrument each delivery attempt with a classifying OpenTelemetry span + // (see instrumentTransport). Keep the leaf's closer so shutdown still QUITs + // the pooled connection — observability wrappers do not forward Close. + tr := instrumentTransport(leaf) return newService(tr, leaf, cfg.From, cfg.ReplyTo, cfg.FrontendURL) } diff --git a/api/internal/mail/otel.go b/api/internal/mail/otel.go new file mode 100644 index 00000000..95255379 --- /dev/null +++ b/api/internal/mail/otel.go @@ -0,0 +1,90 @@ +package mail + +import ( + "context" + "errors" + + "github.com/friendsofshopware/shopmon/api/internal/otelx" + gomailer "github.com/shyim/go-mailer" + "github.com/shyim/go-mailer/middleware" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" +) + +// Span name matches go-mailer's otelmw default so existing Datadog dashboards +// keep working after we swap in a classifying tracer. +const mailSpanName = "gomailer.send" + +// instrumentTransport wraps leaf with an OpenTelemetry client span per Send +// attempt. Soft SMTP failures (421/450/451/452) and retryable network blips +// set error.expected=true and status Ok; other failures keep status Error. +// +// Outcome volume for alerts stays on shopmon.mail.send (package metrics). We +// intentionally do not use otelmw.New here: its Span.SetError path cannot +// classify expected degradations. +func instrumentTransport(leaf gomailer.Transport) gomailer.Transport { + return middleware.Wrap(leaf, middleware.Observability( + middleware.WithTracer(&classifyingMailTracer{ + tracer: otel.Tracer("shopmon/mail"), + }), + middleware.WithSpanName(mailSpanName), + )) +} + +type classifyingMailTracer struct { + tracer trace.Tracer +} + +func (t *classifyingMailTracer) Start(ctx context.Context, name string) (context.Context, middleware.Span) { + ctx, span := t.tracer.Start(ctx, name, trace.WithSpanKind(trace.SpanKindClient)) + return ctx, &classifyingMailSpan{span: span} +} + +type classifyingMailSpan struct { + span trace.Span + lastErr error +} + +func (s *classifyingMailSpan) SetAttributes(attrs ...middleware.Attr) { + if len(attrs) == 0 { + return + } + kvs := make([]attribute.KeyValue, 0, len(attrs)) + for _, a := range attrs { + switch a.Kind { + case middleware.KindInt: + kvs = append(kvs, attribute.Int64(a.Key, a.Int)) + case middleware.KindBool: + kvs = append(kvs, attribute.Bool(a.Key, a.Bool)) + default: + kvs = append(kvs, attribute.String(a.Key, a.Str)) + } + } + s.span.SetAttributes(kvs...) +} + +func (s *classifyingMailSpan) RecordError(err error) { + // Stash until SetError so we can choose expected vs hard. The observability + // middleware always calls RecordError then SetError on failure. + s.lastErr = err +} + +func (s *classifyingMailSpan) SetError(description string) { + err := s.lastErr + if IsExpectedSMTPError(err) { + otelx.RecordExpected(s.span, err) + var te *gomailer.TransportError + if errors.As(err, &te) && te.Code != 0 { + s.span.SetAttributes(attribute.Int("smtp.response.code", te.Code)) + } + return + } + if err != nil { + s.span.RecordError(err) + } + s.span.SetStatus(codes.Error, description) +} + +func (s *classifyingMailSpan) End() { s.span.End() } diff --git a/api/internal/mail/smtp_expected.go b/api/internal/mail/smtp_expected.go new file mode 100644 index 00000000..cf81a18e --- /dev/null +++ b/api/internal/mail/smtp_expected.go @@ -0,0 +1,35 @@ +package mail + +import ( + "errors" + + "github.com/friendsofshopware/shopmon/api/internal/otelx" + gomailer "github.com/shyim/go-mailer" +) + +// SMTPCodeExpected reports whether an SMTP response code is a soft/transient +// failure (SES 451 timeouts, greylisting, mailbox busy, etc.). +// +// 421/450/451/452 are widely treated as retryable; permanent 5xx rejects and +// other 4xx (e.g. 550) are hard failures. +func SMTPCodeExpected(code int) bool { + switch code { + case 421, 450, 451, 452: + return true + default: + return false + } +} + +// IsExpectedSMTPError reports whether err is (or wraps) a retryable SMTP +// transport failure or a retryable network blip talking to the relay. +func IsExpectedSMTPError(err error) bool { + if err == nil { + return false + } + var te *gomailer.TransportError + if errors.As(err, &te) && SMTPCodeExpected(te.Code) { + return true + } + return otelx.IsRetryableNetError(err) +} diff --git a/api/internal/mail/smtp_expected_test.go b/api/internal/mail/smtp_expected_test.go new file mode 100644 index 00000000..e89867e0 --- /dev/null +++ b/api/internal/mail/smtp_expected_test.go @@ -0,0 +1,39 @@ +package mail + +import ( + "errors" + "net" + "syscall" + "testing" + + gomailer "github.com/shyim/go-mailer" + "github.com/stretchr/testify/assert" +) + +func TestSMTPCodeExpected(t *testing.T) { + for _, code := range []int{421, 450, 451, 452} { + assert.True(t, SMTPCodeExpected(code), "code %d", code) + } + for _, code := range []int{0, 250, 550, 554, 400} { + assert.False(t, SMTPCodeExpected(code), "code %d", code) + } +} + +func TestIsExpectedSMTPError(t *testing.T) { + assert.False(t, IsExpectedSMTPError(nil)) + + soft := gomailer.NewTransportError("timeout") + soft.Code = 451 + assert.True(t, IsExpectedSMTPError(soft)) + assert.True(t, IsExpectedSMTPError(errors.Join(errors.New("wrap"), soft))) + + hard := gomailer.NewTransportError("mailbox missing") + hard.Code = 550 + assert.False(t, IsExpectedSMTPError(hard)) + + assert.True(t, IsExpectedSMTPError(&net.OpError{ + Op: "dial", + Net: "tcp", + Err: syscall.ECONNREFUSED, + })) +} diff --git a/api/internal/monitoring/scrape/service.go b/api/internal/monitoring/scrape/service.go index 1b31bac2..d6414812 100644 --- a/api/internal/monitoring/scrape/service.go +++ b/api/internal/monitoring/scrape/service.go @@ -15,6 +15,7 @@ import ( "github.com/friendsofshopware/shopmon/api/internal/mail" "github.com/friendsofshopware/shopmon/api/internal/metrics" "github.com/friendsofshopware/shopmon/api/internal/notify" + "github.com/friendsofshopware/shopmon/api/internal/otelx" "github.com/friendsofshopware/shopmon/api/internal/ptr" "github.com/friendsofshopware/shopmon/api/internal/shopware/checker" "github.com/jackc/pgx/v5/pgxpool" @@ -125,8 +126,10 @@ func (h *Service) scrapeEnvironment(ctx context.Context, env queries.GetAllEnvir authCtx, authSpan := tracer.Start(ctx, "environment.scrape.authenticate") err := client.Authenticate(authCtx) if err != nil { - authSpan.RecordError(err) - authSpan.SetStatus(codes.Error, err.Error()) + // Tenant-side 401/403 (and other expected dependency statuses) must + // not inflate APM error rate; shopmon.scrape.outcome=auth_error + // remains the alert signal (#793). + otelx.RecordDependency(authSpan, err) } authSpan.End() diff --git a/api/internal/monitoring/sitespeed/service.go b/api/internal/monitoring/sitespeed/service.go index 6d651674..0a3f868b 100644 --- a/api/internal/monitoring/sitespeed/service.go +++ b/api/internal/monitoring/sitespeed/service.go @@ -4,6 +4,7 @@ import ( "bytes" "context" "encoding/json" + "errors" "fmt" "io" "log/slog" @@ -15,8 +16,14 @@ import ( "github.com/friendsofshopware/shopmon/api/internal/database/queries" "github.com/friendsofshopware/shopmon/api/internal/httputil" "github.com/friendsofshopware/shopmon/api/internal/metrics" + "github.com/friendsofshopware/shopmon/api/internal/otelx" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/trace" ) +var tracer = otel.Tracer("shopmon/monitoring/sitespeed") + type Service struct { queries *queries.Queries cfg *config.Config @@ -44,6 +51,11 @@ func (s *Service) Scrape(ctx context.Context, environmentID int32) (err error) { } func (s *Service) scrapeEnvironment(ctx context.Context, env queries.GetEnvironmentsWithSitespeedEnabledRow) (err error) { + ctx, span := tracer.Start(ctx, "sitespeed.scrape", + trace.WithAttributes(attribute.Int("environment.id", int(env.ID))), + ) + defer span.End() + log := slog.With("environmentId", env.ID) if s.cfg.SitespeedEndpoint == "" || s.cfg.SitespeedAPIKey == "" { @@ -54,6 +66,10 @@ func (s *Service) scrapeEnvironment(ctx context.Context, env queries.GetEnvironm defer func() { if err != nil { + // 503 / connection-refused are retryable (go-queue retries the job); + // mark expected so intermediate attempts do not dominate APM errors. + // shopmon.sitespeed.outcome still counts every failure. + recordSitespeedSpan(span, err) metrics.RecordSitespeedOutcome(ctx, metrics.OutcomeError) return } @@ -99,7 +115,10 @@ func (s *Service) scrapeEnvironment(ctx context.Context, env queries.GetEnvironm resp, err := httputil.NewHTTPClient(httputil.WithTimeout(300 * time.Second)).Do(req) if err != nil { - return fmt.Errorf("call sitespeed: %w", err) + return &sitespeedError{ + err: fmt.Errorf("call sitespeed: %w", err), + retryable: otelx.IsRetryableNetError(err), + } } defer func() { _ = resp.Body.Close() }() @@ -108,7 +127,11 @@ func (s *Service) scrapeEnvironment(ctx context.Context, env queries.GetEnvironm return fmt.Errorf("read sitespeed response for environment %d: %w", env.ID, err) } if resp.StatusCode >= 400 { - return fmt.Errorf("sitespeed error (%d): %s", resp.StatusCode, string(body)) + return &sitespeedError{ + err: fmt.Errorf("sitespeed error (%d): %s", resp.StatusCode, string(body)), + statusCode: resp.StatusCode, + retryable: otelx.HTTPClientStatusExpected(resp.StatusCode), + } } // Parse response and save metrics @@ -149,3 +172,26 @@ func (s *Service) scrapeEnvironment(ctx context.Context, env queries.GetEnvironm log.Info("sitespeed scrape completed") return nil } + +// sitespeedError wraps an upstream Sitespeed failure and whether the job should +// treat it as an expected/retryable dependency degradation for span status. +type sitespeedError struct { + err error + statusCode int + retryable bool +} + +func (e *sitespeedError) Error() string { return e.err.Error() } +func (e *sitespeedError) Unwrap() error { return e.err } + +// HTTPStatusCode exposes a positive status for otelx classification when set. +func (e *sitespeedError) HTTPStatusCode() int { return e.statusCode } + +func recordSitespeedSpan(span trace.Span, err error) { + var se *sitespeedError + if errors.As(err, &se) && se.retryable { + otelx.RecordExpected(span, err) + return + } + otelx.RecordDependency(span, err) +} diff --git a/api/internal/otelx/expected.go b/api/internal/otelx/expected.go new file mode 100644 index 00000000..fc4da988 --- /dev/null +++ b/api/internal/otelx/expected.go @@ -0,0 +1,180 @@ +// Package otelx classifies expected/transient dependency failures for OpenTelemetry +// spans so Datadog APM error rate reflects shopmon bugs rather than tenant-side +// or retryable upstream noise. +// +// Taxonomy (keep cardinality low — only these stable attributes): +// +// - error.expected=true — this failure is an expected dependency degradation +// (rate limit, tenant auth, retryable upstream 5xx, etc.). Prefer leaving +// span status Ok for these so they do not count toward APM error rate. +// Alerts for real errors: +// +// status:error -@error.expected:true +// +// - Hard failures (panics, unexpected 5xx from our API, exhausted non-retryable +// job errors) keep status=Error and MUST NOT set error.expected. +// +// Outcome counters from package metrics (shopmon.*.outcome) remain the cheap +// signal for rate_limited / auth_error volumes; this package only adjusts spans. +// +// SMTP soft-failure classification lives in package mail (keeps go-mailer out of +// the shared HTTP client dependency graph). +package otelx + +import ( + "errors" + "net" + "net/http" + "os" + "syscall" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" +) + +// AttrErrorExpected is the stable boolean span attribute used to mark +// expected/degraded dependency failures. Datadog query to find real errors: +// +// status:error -@error.expected:true +const AttrErrorExpected = "error.expected" + +// ErrorExpectedAttr is the attribute.KeyValue form of AttrErrorExpected=true. +var ErrorExpectedAttr = attribute.Bool(AttrErrorExpected, true) + +// HTTPClientStatusExpected reports whether an outbound HTTP status code is an +// expected dependency degradation rather than a shopmon bug. +// +// Included: +// - 401/403 — tenant shop credentials / ACL (not our bug) +// - 408/425/429 — timeouts / rate limits (retried or aborted for later retry) +// - 502/503/504 — retryable upstream gateway failures (e.g. Sitespeed) +// +// Excluded (still Error): 400/404/500 and other unexpected statuses. +func HTTPClientStatusExpected(code int) bool { + switch code { + case http.StatusUnauthorized, // 401 + http.StatusForbidden, // 403 + http.StatusRequestTimeout, // 408 + http.StatusTooEarly, // 425 + http.StatusTooManyRequests, // 429 + http.StatusBadGateway, // 502 + http.StatusServiceUnavailable, // 503 + http.StatusGatewayTimeout: // 504 + return true + default: + return false + } +} + +// IsRetryableNetError reports connection-refused / reset / timeout style errors +// that background jobs will retry (Sitespeed down, brief relay blip, etc.). +func IsRetryableNetError(err error) bool { + if err == nil { + return false + } + if errors.Is(err, syscall.ECONNREFUSED) || + errors.Is(err, syscall.ECONNRESET) || + errors.Is(err, syscall.ETIMEDOUT) { + return true + } + var opErr *net.OpError + if errors.As(err, &opErr) { + return true + } + var syscallErr *os.SyscallError + if errors.As(err, &syscallErr) { + return true + } + var netErr net.Error + if errors.As(err, &netErr) && netErr.Timeout() { + return true + } + return false +} + +// httpStatusCoder is implemented by dependency API errors (shopware.ApiError, +// shopwareaccount.APIError) so call sites can classify without switching on +// concrete types here. +type httpStatusCoder interface { + HTTPStatusCode() int +} + +// DependencyHTTPStatus extracts an HTTP status from err when it implements +// HTTPStatusCode() with a positive code. +func DependencyHTTPStatus(err error) (int, bool) { + var h httpStatusCoder + if errors.As(err, &h) { + if code := h.HTTPStatusCode(); code > 0 { + return code, true + } + } + return 0, false +} + +// IsExpectedDependencyError reports whether err is a classified expected +// dependency degradation (HTTP status or retryable network error). +// Soft SMTP failures are classified in package mail via IsExpectedSMTPError. +func IsExpectedDependencyError(err error) bool { + if err == nil { + return false + } + if code, ok := DependencyHTTPStatus(err); ok { + return HTTPClientStatusExpected(code) + } + return IsRetryableNetError(err) +} + +// RecordExpected marks a span as an expected dependency degradation: records the +// error as an event, sets error.expected=true, and forces status Ok so Datadog +// error rate is not inflated. Use for intermediate retries and tenant-side +// failures. +// +// codes.Ok is required (not Unset): the Go OTel SDK will not downgrade Error→Unset. +func RecordExpected(span trace.Span, err error) { + if !span.IsRecording() { + return + } + span.SetAttributes(ErrorExpectedAttr) + if err != nil { + span.RecordError(err) + } + span.SetStatus(codes.Ok, "") +} + +// RecordExpectedHTTP is like RecordExpected when the HTTP status is known. +func RecordExpectedHTTP(span trace.Span, statusCode int, err error) { + if !span.IsRecording() { + return + } + span.SetAttributes( + ErrorExpectedAttr, + attribute.Int("http.response.status_code", statusCode), + ) + if err != nil { + span.RecordError(err) + } + span.SetStatus(codes.Ok, "") +} + +// RecordHard marks a span as a real failure: RecordError + status Error, without +// error.expected. Use for panics, unexpected bugs, and final hard failures. +func RecordHard(span trace.Span, err error) { + if !span.IsRecording() || err == nil { + return + } + span.RecordError(err) + span.SetStatus(codes.Error, err.Error()) +} + +// RecordDependency records err on span using expected-vs-hard classification. +func RecordDependency(span trace.Span, err error) { + if err == nil { + return + } + if IsExpectedDependencyError(err) { + RecordExpected(span, err) + return + } + RecordHard(span, err) +} diff --git a/api/internal/otelx/expected_test.go b/api/internal/otelx/expected_test.go new file mode 100644 index 00000000..9ad6d6f1 --- /dev/null +++ b/api/internal/otelx/expected_test.go @@ -0,0 +1,113 @@ +package otelx + +import ( + "context" + "errors" + "fmt" + "net" + "net/http" + "syscall" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +func TestHTTPClientStatusExpected(t *testing.T) { + expected := []int{401, 403, 408, 425, 429, 502, 503, 504} + for _, code := range expected { + assert.True(t, HTTPClientStatusExpected(code), "status %d", code) + } + + hard := []int{0, 200, 301, 400, 404, 418, 500, 501, 505} + for _, code := range hard { + assert.False(t, HTTPClientStatusExpected(code), "status %d", code) + } +} + +type stubAPIError struct { + code int +} + +func (e *stubAPIError) Error() string { return fmt.Sprintf("status %d", e.code) } +func (e *stubAPIError) HTTPStatusCode() int { return e.code } + +func TestIsExpectedDependencyError(t *testing.T) { + assert.False(t, IsExpectedDependencyError(nil)) + assert.True(t, IsExpectedDependencyError(&stubAPIError{code: 429})) + assert.True(t, IsExpectedDependencyError(&stubAPIError{code: 401})) + assert.False(t, IsExpectedDependencyError(&stubAPIError{code: 500})) + assert.False(t, IsExpectedDependencyError(&stubAPIError{code: 0})) + + assert.True(t, IsExpectedDependencyError(fmt.Errorf("wrap: %w", &stubAPIError{code: 503}))) + assert.True(t, IsExpectedDependencyError(&net.OpError{ + Op: "dial", + Net: "tcp", + Err: syscall.ECONNREFUSED, + })) + assert.False(t, IsExpectedDependencyError(errors.New("boom"))) +} + +func TestRecordExpectedSetsOkAndAttribute(t *testing.T) { + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + ctx, span := tp.Tracer("test").Start(context.Background(), "op") + + err := &stubAPIError{code: 429} + RecordExpected(span, err) + span.End() + require.NoError(t, tp.Shutdown(ctx)) + + require.Len(t, sr.Ended(), 1) + got := sr.Ended()[0] + assert.Equal(t, codes.Ok, got.Status().Code) + assert.True(t, hasBoolAttr(got.Attributes(), AttrErrorExpected, true)) + require.NotEmpty(t, got.Events(), "RecordError should add an event") +} + +func TestRecordHardSetsErrorWithoutExpected(t *testing.T) { + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + ctx, span := tp.Tracer("test").Start(context.Background(), "op") + + RecordHard(span, errors.New("bug")) + span.End() + require.NoError(t, tp.Shutdown(ctx)) + + require.Len(t, sr.Ended(), 1) + got := sr.Ended()[0] + assert.Equal(t, codes.Error, got.Status().Code) + assert.False(t, hasBoolAttr(got.Attributes(), AttrErrorExpected, true)) +} + +func TestRecordDependencyClassifies(t *testing.T) { + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + tr := tp.Tracer("test") + + _, span := tr.Start(context.Background(), "expected") + RecordDependency(span, &stubAPIError{code: http.StatusTooManyRequests}) + span.End() + + _, span = tr.Start(context.Background(), "hard") + RecordDependency(span, errors.New("unexpected")) + span.End() + + require.NoError(t, tp.Shutdown(context.Background())) + require.Len(t, sr.Ended(), 2) + assert.Equal(t, codes.Ok, sr.Ended()[0].Status().Code) + assert.Equal(t, codes.Error, sr.Ended()[1].Status().Code) +} + +func hasBoolAttr(attrs []attribute.KeyValue, key string, want bool) bool { + for _, a := range attrs { + if string(a.Key) == key && a.Value.Type() == attribute.BOOL && a.Value.AsBool() == want { + return true + } + } + return false +} diff --git a/api/internal/otelx/http_transport.go b/api/internal/otelx/http_transport.go new file mode 100644 index 00000000..f2997fab --- /dev/null +++ b/api/internal/otelx/http_transport.go @@ -0,0 +1,82 @@ +package otelx + +import ( + "context" + "net/http" + + "go.opentelemetry.io/otel/trace" +) + +// spanBoxKey is an unexported context key. expectedStatusTransport stashes an +// empty box in the request context; spanCaptureTransport (inside otelhttp) +// fills it with the client span so expectedStatusTransport can downgrade +// expected 4xx/5xx from Error→Ok after otelhttp has set status. +type spanBoxKey struct{} + +type spanBox struct { + span trace.Span +} + +// WrapClientTransport wraps base (typically an otelhttp.Transport) so expected +// dependency HTTP statuses do not count as APM errors. +// +// Call as: +// +// otelx.WrapClientTransport(otelhttp.NewTransport(base, ...)) +// +// Order matters: this wrapper must sit *outside* otelhttp so it runs after +// otelhttp sets span status from the response code, and *before* the body is +// closed (which ends the span). +func WrapClientTransport(otelTransport http.RoundTripper) http.RoundTripper { + if otelTransport == nil { + otelTransport = http.DefaultTransport + } + return &expectedStatusTransport{base: otelTransport} +} + +// CaptureClientSpan returns a RoundTripper that records the active client span +// from the request context into a box placed by WrapClientTransport. Use it as +// the *base* of otelhttp.NewTransport: +// +// otelhttp.NewTransport(otelx.CaptureClientSpan(base), ...) +func CaptureClientSpan(base http.RoundTripper) http.RoundTripper { + if base == nil { + base = http.DefaultTransport + } + return &spanCaptureTransport{base: base} +} + +type spanCaptureTransport struct { + base http.RoundTripper +} + +func (t *spanCaptureTransport) RoundTrip(req *http.Request) (*http.Response, error) { + if box, ok := req.Context().Value(spanBoxKey{}).(*spanBox); ok && box != nil { + box.span = trace.SpanFromContext(req.Context()) + } + return t.base.RoundTrip(req) +} + +type expectedStatusTransport struct { + base http.RoundTripper +} + +func (t *expectedStatusTransport) RoundTrip(req *http.Request) (*http.Response, error) { + box := &spanBox{} + ctx := context.WithValue(req.Context(), spanBoxKey{}, box) + req = req.WithContext(ctx) + + resp, err := t.base.RoundTrip(req) + if err != nil || resp == nil { + return resp, err + } + if !HTTPClientStatusExpected(resp.StatusCode) { + return resp, nil + } + if box.span != nil && box.span.IsRecording() { + // otelhttp already set status=Error and error.type=. Downgrade + // status so APM error rate stays clean; keep attributes for forensics. + RecordExpectedHTTP(box.span, resp.StatusCode, nil) + } + return resp, nil +} diff --git a/api/internal/otelx/http_transport_test.go b/api/internal/otelx/http_transport_test.go new file mode 100644 index 00000000..6a8d326a --- /dev/null +++ b/api/internal/otelx/http_transport_test.go @@ -0,0 +1,82 @@ +package otelx + +import ( + "context" + "io" + "net/http" + "net/http/httptest" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" + "go.opentelemetry.io/otel/codes" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +func TestWrapClientTransportDowngradesExpectedStatus(t *testing.T) { + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + + upstream := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusTooManyRequests) + _, _ = io.WriteString(w, "slow down") + })) + t.Cleanup(upstream.Close) + + client := &http.Client{ + Transport: WrapClientTransport( + otelhttp.NewTransport( + CaptureClientSpan(http.DefaultTransport), + otelhttp.WithTracerProvider(tp), + ), + ), + } + + req, err := http.NewRequestWithContext(context.Background(), http.MethodGet, upstream.URL, nil) + require.NoError(t, err) + resp, err := client.Do(req) + require.NoError(t, err) + _, _ = io.Copy(io.Discard, resp.Body) + require.NoError(t, resp.Body.Close()) + require.Equal(t, http.StatusTooManyRequests, resp.StatusCode) + + require.NoError(t, tp.Shutdown(context.Background())) + require.NotEmpty(t, sr.Ended()) + span := sr.Ended()[0] + assert.Equal(t, codes.Ok, span.Status().Code, "429 must not remain status=Error") + assert.True(t, hasBoolAttr(span.Attributes(), AttrErrorExpected, true)) +} + +func TestWrapClientTransportKeepsHardStatus(t *testing.T) { + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + + upstream := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusInternalServerError) + })) + t.Cleanup(upstream.Close) + + client := &http.Client{ + Transport: WrapClientTransport( + otelhttp.NewTransport( + CaptureClientSpan(http.DefaultTransport), + otelhttp.WithTracerProvider(tp), + ), + ), + } + + req, err := http.NewRequestWithContext(context.Background(), http.MethodGet, upstream.URL, nil) + require.NoError(t, err) + resp, err := client.Do(req) + require.NoError(t, err) + _, _ = io.Copy(io.Discard, resp.Body) + require.NoError(t, resp.Body.Close()) + + require.NoError(t, tp.Shutdown(context.Background())) + require.NotEmpty(t, sr.Ended()) + span := sr.Ended()[0] + assert.Equal(t, codes.Error, span.Status().Code) + assert.False(t, hasBoolAttr(span.Attributes(), AttrErrorExpected, true)) +} diff --git a/api/internal/shopware/client.go b/api/internal/shopware/client.go index a2c5db15..e9d47aa1 100644 --- a/api/internal/shopware/client.go +++ b/api/internal/shopware/client.go @@ -54,6 +54,9 @@ func (e *ApiError) Error() string { return fmt.Sprintf("shopware api error (status %d): %s", e.StatusCode, e.Body) } +// HTTPStatusCode exposes the status for otelx expected-dependency classification. +func (e *ApiError) HTTPStatusCode() int { return e.StatusCode } + func NewClient(baseURL, clientID, clientSecret, shopToken string) *Client { return &Client{ baseURL: strings.TrimRight(baseURL, "/"), diff --git a/api/internal/shopwareaccount/retry.go b/api/internal/shopwareaccount/retry.go index f96d299b..6a38a36f 100644 --- a/api/internal/shopwareaccount/retry.go +++ b/api/internal/shopwareaccount/retry.go @@ -28,6 +28,9 @@ func (e *APIError) Error() string { return fmt.Sprintf("store api returned status %d", e.StatusCode) } +// HTTPStatusCode exposes the status for otelx expected-dependency classification. +func (e *APIError) HTTPStatusCode() int { return e.StatusCode } + // IsRateLimited reports whether err is (or wraps) a store API 429 response. func IsRateLimited(err error) bool { var apiErr *APIError