diff --git a/weed/s3api/s3api_object_handlers.go b/weed/s3api/s3api_object_handlers.go index 8e5abaac2..87b71b017 100644 --- a/weed/s3api/s3api_object_handlers.go +++ b/weed/s3api/s3api_object_handlers.go @@ -772,7 +772,6 @@ func (s3a *S3ApiServer) GetObjectHandler(w http.ResponseWriter, r *http.Request) return } if objectEntryForSSE == nil { - // Not found, return error early to avoid another lookup in proxyToFiler s3err.WriteErrorResponse(w, r, s3err.ErrNoSuchKey) return } @@ -2274,7 +2273,6 @@ func (s3a *S3ApiServer) HeadObjectHandler(w http.ResponseWriter, r *http.Request return } if objectEntryForSSE == nil { - // Not found, return error early to avoid another lookup in proxyToFiler s3err.WriteErrorResponse(w, r, s3err.ErrNoSuchKey) return } diff --git a/weed/s3api/s3api_object_handlers_delete.go b/weed/s3api/s3api_object_handlers_delete.go index cc031d691..39742ed51 100644 --- a/weed/s3api/s3api_object_handlers_delete.go +++ b/weed/s3api/s3api_object_handlers_delete.go @@ -256,6 +256,7 @@ func (s3a *S3ApiServer) DeleteObjectHandler(w http.ResponseWriter, r *http.Reque if auditLog != nil { auditLog.Key = strings.TrimPrefix(object, "/") s3err.PostAccessLog(*auditLog) + s3err.MarkAuditLogged(r) } stats_collect.RecordBucketActiveTime(bucket) @@ -404,6 +405,7 @@ func (s3a *S3ApiServer) DeleteMultipleObjectsHandler(w http.ResponseWriter, r *h if auditLog != nil { auditLog.Key = object.Key s3err.PostAccessLog(*auditLog) + s3err.MarkAuditLogged(r) } } diff --git a/weed/s3api/s3err/audit_fluent.go b/weed/s3api/s3err/audit_fluent.go index 69a8ad54e..f037d8f59 100644 --- a/weed/s3api/s3err/audit_fluent.go +++ b/weed/s3api/s3err/audit_fluent.go @@ -1,12 +1,14 @@ package s3err import ( + "context" "encoding/json" "fmt" "net" "net/http" "os" "strings" + "sync/atomic" "time" "github.com/fluent/fluent-logger-golang/fluent" @@ -181,6 +183,14 @@ func GetAccessLog(r *http.Request, HTTPStatusCode int, s3errCode ErrorCode) *Acc } func PostLog(r *http.Request, HTTPStatusCode int, errorCode ErrorCode) { + if r == nil { + return + } + // Mark before the Logger nil-check so the middleware fallback in track() + // still sees that audit was handled by the caller in deployments that + // haven't configured fluent — keeps the flag behavior consistent and + // makes wiring testable without standing up a fluent server. + markAuditLogged(r) if Logger == nil { return } @@ -197,3 +207,50 @@ func PostAccessLog(log AccessLog) { glog.Warning("Error while posting log: ", err) } } + +// auditLogCtxKey identifies the per-request flag used to detect whether an +// audit entry has already been emitted, so middleware can supply a fallback +// log for handlers that don't call PostLog themselves without double-logging +// the ones that do. +type auditLogCtxKey struct{} + +// EnsureAuditTracking attaches an audit-tracking flag to the request context +// if one is not already present. Safe to call when no fluent logger is +// configured; the flag is harmless in that case. +func EnsureAuditTracking(r *http.Request) *http.Request { + if r == nil { + return nil + } + if v, ok := r.Context().Value(auditLogCtxKey{}).(*atomic.Bool); ok && v != nil { + return r + } + flag := new(atomic.Bool) + return r.WithContext(context.WithValue(r.Context(), auditLogCtxKey{}, flag)) +} + +// MarkAuditLogged signals that an audit entry has already been emitted for r. +// Callers that emit logs via paths other than PostLog (e.g. PostAccessLog in +// batch delete) should invoke this so the middleware fallback skips r. +func MarkAuditLogged(r *http.Request) { + markAuditLogged(r) +} + +func markAuditLogged(r *http.Request) { + if r == nil { + return + } + if v, ok := r.Context().Value(auditLogCtxKey{}).(*atomic.Bool); ok && v != nil { + v.Store(true) + } +} + +// AuditAlreadyLogged reports whether PostLog (or MarkAuditLogged) has run for r. +func AuditAlreadyLogged(r *http.Request) bool { + if r == nil { + return false + } + if v, ok := r.Context().Value(auditLogCtxKey{}).(*atomic.Bool); ok && v != nil { + return v.Load() + } + return false +} diff --git a/weed/s3api/s3err/audit_fluent_test.go b/weed/s3api/s3err/audit_fluent_test.go index 4d06ecdb4..710a705cc 100644 --- a/weed/s3api/s3err/audit_fluent_test.go +++ b/weed/s3api/s3err/audit_fluent_test.go @@ -85,3 +85,18 @@ func TestGetAccessLogRemoteIP(t *testing.T) { }) } } + +func TestAuditTrackingFlag(t *testing.T) { + req := httptest.NewRequest(http.MethodGet, "/bucket/object", nil) + assert.False(t, AuditAlreadyLogged(req), "untracked request reports not logged") + + tracked := EnsureAuditTracking(req) + assert.NotSame(t, req, tracked, "EnsureAuditTracking returns a new request when no flag is present") + assert.False(t, AuditAlreadyLogged(tracked), "tracked request starts unlogged") + + again := EnsureAuditTracking(tracked) + assert.Same(t, tracked, again, "EnsureAuditTracking is idempotent when flag already present") + + MarkAuditLogged(tracked) + assert.True(t, AuditAlreadyLogged(tracked), "flag flips after MarkAuditLogged") +} diff --git a/weed/s3api/stats.go b/weed/s3api/stats.go index 14c0ad150..00ff38dad 100644 --- a/weed/s3api/stats.go +++ b/weed/s3api/stats.go @@ -8,6 +8,7 @@ import ( "github.com/seaweedfs/seaweedfs/weed/util/version" "github.com/seaweedfs/seaweedfs/weed/s3api/s3_constants" + "github.com/seaweedfs/seaweedfs/weed/s3api/s3err" stats_collect "github.com/seaweedfs/seaweedfs/weed/stats" ) @@ -20,6 +21,10 @@ func track(f http.HandlerFunc, action string) http.HandlerFunc { bucket, _ := s3_constants.GetBucketAndObject(r) w.Header().Set("Server", "SeaweedFS "+version.VERSION) recorder := stats_collect.NewStatusResponseWriter(w) + // Attach an audit-tracking flag to the request so handlers that call + // PostLog directly mark it; we emit a fallback entry afterward for + // handlers (e.g. successful GET/HEAD object) that don't. + r = s3err.EnsureAuditTracking(r) start := time.Now() f(recorder, r) if recorder.Status == http.StatusForbidden { @@ -28,6 +33,9 @@ func track(f http.HandlerFunc, action string) http.HandlerFunc { stats_collect.S3RequestHistogram.WithLabelValues(action, bucket).Observe(time.Since(start).Seconds()) stats_collect.S3RequestCounter.WithLabelValues(action, strconv.Itoa(recorder.Status), bucket).Inc() stats_collect.RecordBucketActiveTime(bucket) + if !s3err.AuditAlreadyLogged(r) { + s3err.PostLog(r, recorder.Status, s3err.ErrNone) + } } } diff --git a/weed/s3api/stats_test.go b/weed/s3api/stats_test.go new file mode 100644 index 000000000..63d019b90 --- /dev/null +++ b/weed/s3api/stats_test.go @@ -0,0 +1,51 @@ +package s3api + +import ( + "net/http" + "net/http/httptest" + "testing" + + "github.com/seaweedfs/seaweedfs/weed/s3api/s3err" + "github.com/stretchr/testify/assert" +) + +// TestTrackAuditFallbackForDirectWriteHeader covers the regression behind +// issue #9463: handlers that bypass writeSuccessResponse helpers and call +// w.WriteHeader directly (GetObjectHandler stream path, HeadObjectHandler, +// GetBucketEncryption, GetObjectLockConfiguration, etc.) used to drop their +// audit entry. track() must mark the request as audited via a fallback +// PostLog after the handler returns. +func TestTrackAuditFallbackForDirectWriteHeader(t *testing.T) { + var captured *http.Request + handler := func(w http.ResponseWriter, r *http.Request) { + captured = r + w.WriteHeader(http.StatusOK) + } + wrapped := track(handler, "GET") + wrapped(httptest.NewRecorder(), httptest.NewRequest(http.MethodGet, "/bucket/object", nil)) + + if assert.NotNil(t, captured, "handler must have been invoked") { + assert.True(t, s3err.AuditAlreadyLogged(captured), + "track must emit fallback audit when handler writes response directly") + } +} + +// TestTrackAuditSkipsFallbackWhenHandlerEmits guards against double logging: +// handlers that already call PostLog (e.g. via writeSuccessResponseXML or +// WriteErrorResponse) flip the audit flag, and track must observe that and +// not re-emit. +func TestTrackAuditSkipsFallbackWhenHandlerEmits(t *testing.T) { + var captured *http.Request + handler := func(w http.ResponseWriter, r *http.Request) { + captured = r + s3err.PostLog(r, http.StatusOK, s3err.ErrNone) + w.WriteHeader(http.StatusOK) + } + wrapped := track(handler, "PUT") + wrapped(httptest.NewRecorder(), httptest.NewRequest(http.MethodPut, "/bucket/object", nil)) + + if assert.NotNil(t, captured) { + assert.True(t, s3err.AuditAlreadyLogged(captured), + "flag must be set after handler PostLog") + } +}