diff --git a/pkg/atproto/resolver.go b/pkg/atproto/resolver.go index c36a4fa..03447e9 100644 --- a/pkg/atproto/resolver.go +++ b/pkg/atproto/resolver.go @@ -2,15 +2,50 @@ package atproto import ( "context" + "errors" "fmt" "io" + "net" "net/http" "strings" "time" + "github.com/bluesky-social/indigo/atproto/identity" "github.com/bluesky-social/indigo/atproto/syntax" ) +// ErrHoldDIDPermanent marks a hold-DID resolution failure that no retry can +// fix: a malformed identifier, or a DID whose document does not exist. It is a +// fact about stored data — typically a stale or hand-edited sailor profile +// defaultHold — rather than a fault on our side, so callers can log it quietly +// instead of at ERROR and avoid burying real faults. Transient failures (a PLC +// blip, a network error) deliberately do not carry it. +var ErrHoldDIDPermanent = errors.New("hold DID is not resolvable") + +// didWebHostUnusable reports whether a did:web identifier names something the +// identity directory can never resolve. The directory requires a plain +// hostname and rejects ports (percent-encoded as %3A), bare IPs, and +// localhost. Detecting those here, rather than string-matching the directory's +// error prose, is what lets ResolveHoldDIDToURL classify the failure as +// permanent. Conservative by design: anything not clearly hopeless is left to +// the transient path, so an unfamiliar failure still surfaces loudly. +func didWebHostUnusable(did string) bool { + host, ok := strings.CutPrefix(did, "did:web:") + if !ok { + return false + } + if i := strings.IndexByte(host, ':'); i != -1 { // path-qualified did:web + host = host[:i] + } + if strings.Contains(host, "%3A") || strings.Contains(host, "%3a") { + return true // a port survived encoding, e.g. localhost%3A8080 + } + if host == "" || host == "localhost" || strings.HasSuffix(host, ".localhost") { + return true + } + return net.ParseIP(host) != nil +} + // holdDIDResolveClient bounds the /.well-known/atproto-did fetch so an // unreachable or slow hold can't stall /auth/token (this resolution runs on the // hot gate + fetch path) past Docker's token-fetch timeout. It's a plain @@ -98,7 +133,7 @@ func ResolveHoldDIDToURL(ctx context.Context, did string) (string, error) { directory := GetDirectory() didParsed, err := syntax.ParseDID(did) if err != nil { - return "", fmt.Errorf("invalid hold DID %q: %w", did, err) + return "", fmt.Errorf("invalid hold DID %q: %w: %w", did, ErrHoldDIDPermanent, err) } ident, err := directory.LookupDID(ctx, didParsed) @@ -109,6 +144,12 @@ func ResolveHoldDIDToURL(ctx context.Context, did string) (string, error) { if testMode && strings.HasPrefix(did, "did:web:") { return DIDWebToURL(did), nil } + // A missing DID document or a structurally unusable did:web will fail + // identically on every retry, so mark it permanent and let callers pick + // a quieter log level. + if errors.Is(err, identity.ErrDIDNotFound) || didWebHostUnusable(did) { + return "", fmt.Errorf("failed to resolve hold DID %s: %w: %w", did, ErrHoldDIDPermanent, err) + } return "", fmt.Errorf("failed to resolve hold DID %s: %w", did, err) } diff --git a/pkg/atproto/resolver_test.go b/pkg/atproto/resolver_test.go index a5e59e8..7d4f881 100644 --- a/pkg/atproto/resolver_test.go +++ b/pkg/atproto/resolver_test.go @@ -665,3 +665,31 @@ func TestResolveHandleToDIDContextCancellation(t *testing.T) { t.Log("Expected error due to context cancellation, but got success (identifier may have been parsed without network)") } } + +// TestDIDWebHostUnusable pins the classification that decides whether a hold +// resolution failure is logged at DEBUG or ERROR. Getting this wrong in the +// permissive direction is the safe failure (a real fault stays loud); getting +// it wrong the other way buries genuine errors, which is what BUGS finding 21 +// was about. +func TestDIDWebHostUnusable(t *testing.T) { + tests := []struct { + name string + did string + want bool + }{ + {"port survives percent-encoding", "did:web:localhost%3A8080", true}, + {"lowercase percent-encoding", "did:web:localhost%3a8080", true}, + {"bare localhost", "did:web:localhost", true}, + {"IPv4 literal", "did:web:172.28.0.3", true}, + {"real hold hostname", "did:web:us-chi1.cove.seamark.dev", false}, + {"path-qualified did:web", "did:web:example.com:user:alice", false}, + {"did:plc is not did:web", "did:plc:wnbpdx4bn5uts5yd2o2g3gnm", false}, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := didWebHostUnusable(tt.did); got != tt.want { + t.Errorf("didWebHostUnusable(%q) = %v, want %v", tt.did, got, tt.want) + } + }) + } +} diff --git a/pkg/auth/hold_remote.go b/pkg/auth/hold_remote.go index 187c650..c9c318d 100644 --- a/pkg/auth/hold_remote.go +++ b/pkg/auth/hold_remote.go @@ -131,10 +131,23 @@ func (a *RemoteHoldAuthorizer) GetCaptainRecord(ctx context.Context, holdDID str "error", err) return staleCached.CaptainRecord, nil } - slog.Error("Captain record fetch failed", - "holdDID", holdDID, - "denial_reason", "captain_record_fetch_failed", - "error", err) + // A hold DID that can never resolve is a property of stored user data + // (a stale or hand-edited sailor profile defaultHold), not a fault on + // our side, and nothing is cached on this path — so it re-logs on every + // single request for that user. Two such accounts once produced 99.9% + // of this service's ERROR lines. Keep ERROR for failures an operator + // could actually act on. + if errors.Is(err, atproto.ErrHoldDIDPermanent) { + slog.Debug("Captain record fetch skipped, hold DID cannot be resolved", + "holdDID", holdDID, + "denial_reason", "captain_record_fetch_failed", + "error", err) + } else { + slog.Error("Captain record fetch failed", + "holdDID", holdDID, + "denial_reason", "captain_record_fetch_failed", + "error", err) + } return nil, fmt.Errorf("failed to get captain record for %s: %w", holdDID, err) }