From 1915565385e0a329e065229454d39821b5b19e3a Mon Sep 17 00:00:00 2001 From: npc0-hue Date: Thu, 6 Aug 2026 16:59:51 +0800 Subject: [PATCH] Log run request signature diagnostics --- platform/service/control.go | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+) diff --git a/platform/service/control.go b/platform/service/control.go index a02d919..f182299 100644 --- a/platform/service/control.go +++ b/platform/service/control.go @@ -7,6 +7,7 @@ import ( "encoding/hex" "errors" "fmt" + "log" "strconv" "strings" "time" @@ -400,25 +401,30 @@ func (svc *CoreService) AuthorizeRunRequestSignature(request domain.RunRequestSi session, err := svc.currentRunSession(request.RunEndpointID, request.SessionToken) if err != nil { + logRunSignatureFailure(request, "session_invalid", err) return err } if strings.TrimSpace(request.Signature) == "" && !session.RequireSignedRequests { return nil } if strings.TrimSpace(request.Timestamp) == "" || strings.TrimSpace(request.Nonce) == "" || strings.TrimSpace(request.Signature) == "" { + logRunSignatureFailure(request, "missing_signed_header", nil) return runAuthenticationError(true) } unixSeconds, err := strconv.ParseInt(request.Timestamp, 10, 64) if err != nil { + logRunSignatureFailure(request, "bad_timestamp", err) return runAuthenticationError(true) } stamp := time.Unix(unixSeconds, 0).UTC() delta := svc.now().Sub(stamp) if delta < -maxRunRequestClockSkew || delta > maxRunRequestClockSkew { + logRunSignatureFailure(request, fmt.Sprintf("clock_skew_%dms", delta.Milliseconds()), nil) return runAuthenticationError(true) } session.UsedNonces = activeRunNonces(session.UsedNonces, svc.now().Add(-maxRunRequestClockSkew)) if len(request.Nonce) > 128 || runNonceSeen(session.UsedNonces, request.Nonce) || len(session.UsedNonces) >= maxRunRequestNonces { + logRunSignatureFailure(request, "nonce_replay_or_limit", nil) return runAuthenticationError(true) } canonical := strings.Join([]string{request.Method, request.Path, request.Timestamp, request.Nonce, request.BodyHash}, "\n") @@ -427,17 +433,48 @@ func (svc *CoreService) AuthorizeRunRequestSignature(request domain.RunRequestSi expected := hex.EncodeToString(mac.Sum(nil)) provided, err := hex.DecodeString(request.Signature) if err != nil || subtle.ConstantTimeCompare([]byte(expected), []byte(hex.EncodeToString(provided))) != 1 { + logRunSignatureFailure(request, "signature_mismatch", err) return runAuthenticationError(true) } session.UsedNonces = append(session.UsedNonces, request.Timestamp+":"+request.Nonce) session.UpdatedAt = svc.now() if err := svc.store.RunControlSessions().Update(session); err != nil { + logRunSignatureFailure(request, "session_update_failed", err) return err } svc.runSessions[request.RunEndpointID] = session + logRunSignatureAccepted(request) return nil } +func logRunSignatureAccepted(request domain.RunRequestSignature) { + log.Printf("PLATFORM phase=run_signature status=accepted endpoint=%s method=%s path=%s timestamp=%s nonce=%s bodyHash=%s signature=%s", safeLogValue(request.RunEndpointID), safeLogValue(request.Method), safeLogValue(request.Path), safeLogValue(request.Timestamp), shortLogValue(request.Nonce), shortLogValue(request.BodyHash), shortLogValue(request.Signature)) +} + +func logRunSignatureFailure(request domain.RunRequestSignature, reason string, err error) { + message := "" + if err != nil { + message = " error=" + safeLogValue(err.Error()) + } + log.Printf("PLATFORM phase=run_signature status=failed reason=%s endpoint=%s method=%s path=%s timestamp=%s nonce=%s bodyHash=%s signature=%s%s", safeLogValue(reason), safeLogValue(request.RunEndpointID), safeLogValue(request.Method), safeLogValue(request.Path), safeLogValue(request.Timestamp), shortLogValue(request.Nonce), shortLogValue(request.BodyHash), shortLogValue(request.Signature), message) +} + +func safeLogValue(value string) string { + value = strings.TrimSpace(value) + if value == "" { + return "-" + } + return strings.NewReplacer("\n", " ", "\r", " ", "\t", " ").Replace(value) +} + +func shortLogValue(value string) string { + value = safeLogValue(value) + if value == "-" || len(value) <= 16 { + return value + } + return value[:12] + "..." + value[len(value)-4:] +} + func activeRunNonces(entries []string, cutoff time.Time) []string { active := make([]string, 0, len(entries)) for _, entry := range entries {