[#1574] object: Introduce debug logging for APE check failures

Signed-off-by: Airat Arifullin <a.arifullin@yadro.com>

cmd/frostfs-node/object.go

@@ -453,6 +453,7 @@ func createAPEService(c *cfg, splitSvc *objectService.TransportSplitter) *object
 			c.binPublicKey,
 		),
 		splitSvc,
+		objectAPE.WithLogger(c.log),
 	)
 }
 

internal/logs/logs.go

@@ -513,4 +513,5 @@ const (
 	FailedToParseIncomingIOTag                                           = "failed to parse incoming IO tag"
 	NotSupportedIncomingIOTagReplacedWithClient                          = "incoming IO tag is not supported, replaced with `client`"
 	FailedToGetNetmapToAdjustIOTag                                       = "failed to get netmap to adjust IO tag, replaced with `client`"
+	APECheckDeniedRequest                                                = "ape check denied request"
 )

pkg/services/object/ape/service.go

@@ -6,10 +6,13 @@ import (
 	"errors"
 	"fmt"
 
+	"git.frostfs.info/TrueCloudLab/frostfs-node/internal/logs"
 	"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/local_object_storage/engine"
+	apecommon "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/common/ape"
 	objectSvc "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/object"
 	getsvc "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/object/get"
 	"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/object/util"
+	"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
 	objectV2 "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/api/object"
 	"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/api/refs"
 	"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/bearer"
@@ -18,16 +21,30 @@ import (
 	oid "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object/id"
 	"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/user"
 	nativeschema "git.frostfs.info/TrueCloudLab/policy-engine/schema/native"
+	"go.uber.org/zap"
 )
 
 var errFailedToCastToRequestContext = errors.New("failed cast to RequestContext")
 
 type Service struct {
+	logger *logger.Logger
+
 	apeChecker Checker
 
 	next objectSvc.ServiceServer
 }
 
+func logChainRouterError(ctx context.Context, logger *logger.Logger, chainRouterErr *apecommon.ChainRouterError) {
+	logger.Debug(ctx, logs.APECheckDeniedRequest,
+		zap.Stringer("status", chainRouterErr.Status()),
+		zap.String("operation", chainRouterErr.Request().Operation()),
+		zap.Any("target", chainRouterErr.Target()),
+		zap.Any("request_properties", chainRouterErr.Request().Properties()),
+		zap.Any("resource_name", chainRouterErr.Resource().Name()),
+		zap.Any("resource_properties", chainRouterErr.Resource().Properties()),
+	)
+}
+
 var _ objectSvc.ServiceServer = (*Service)(nil)
 
 type HeaderProvider interface {
@@ -64,16 +81,31 @@ func NewStorageEngineHeaderProvider(e *engine.StorageEngine, s *getsvc.Service)
 	}
 }
 
-func NewService(apeChecker Checker, next objectSvc.ServiceServer) *Service {
+func NewService(apeChecker Checker, next objectSvc.ServiceServer, opts ...func(s *Service)) *Service {
-	return &Service{
+	s := &Service{
+		logger:     logger.NewLoggerWrapper(zap.L()),
 		apeChecker: apeChecker,
 		next:       next,
 	}
+
+	for _, opt := range opts {
+		opt(s)
+	}
+
+	return s
+}
+
+func WithLogger(logger *logger.Logger) func(s *Service) {
+	return func(s *Service) {
+		s.logger = logger
+	}
 }
 
 type getStreamBasicChecker struct {
 	objectSvc.GetObjectStream
 
+	logger *logger.Logger
+
 	apeChecker Checker
 
 	namespace string
@@ -108,6 +140,10 @@ func (g *getStreamBasicChecker) Send(resp *objectV2.GetResponse) error {
 		}
 
 		if err := g.apeChecker.CheckAPE(g.Context(), prm); err != nil {
+			var chainRouterErr *apecommon.ChainRouterError
+			if errors.As(err, &chainRouterErr) {
+				logChainRouterError(g.Context(), g.logger, chainRouterErr)
+			}
 			return toStatusErr(err)
 		}
 	}
@@ -134,6 +170,7 @@ func (c *Service) Get(request *objectV2.GetRequest, stream objectSvc.GetObjectSt
 
 	return c.next.Get(request, &getStreamBasicChecker{
 		GetObjectStream: stream,
+		logger:          c.logger,
 		apeChecker:      c.apeChecker,
 		namespace:       reqCtx.Namespace,
 		senderKey:       reqCtx.SenderKey,
@@ -144,6 +181,8 @@ func (c *Service) Get(request *objectV2.GetRequest, stream objectSvc.GetObjectSt
 }
 
 type putStreamBasicChecker struct {
+	logger *logger.Logger
+
 	apeChecker Checker
 
 	next objectSvc.PutObjectStream
@@ -180,6 +219,10 @@ func (p *putStreamBasicChecker) Send(ctx context.Context, request *objectV2.PutR
 		}
 
 		if err := p.apeChecker.CheckAPE(ctx, prm); err != nil {
+			var chainRouterErr *apecommon.ChainRouterError
+			if errors.As(err, &chainRouterErr) {
+				logChainRouterError(ctx, p.logger, chainRouterErr)
+			}
 			return toStatusErr(err)
 		}
 	}
@@ -195,12 +238,15 @@ func (c *Service) Put(ctx context.Context) (objectSvc.PutObjectStream, error) {
 	streamer, err := c.next.Put(ctx)
 
 	return &putStreamBasicChecker{
+		logger:     c.logger,
 		apeChecker: c.apeChecker,
 		next:       streamer,
 	}, err
 }
 
 type patchStreamBasicChecker struct {
+	logger *logger.Logger
+
 	apeChecker Checker
 
 	next objectSvc.PatchObjectStream
@@ -240,6 +286,10 @@ func (p *patchStreamBasicChecker) Send(ctx context.Context, request *objectV2.Pa
 		}
 
 		if err := p.apeChecker.CheckAPE(ctx, prm); err != nil {
+			var chainRouterErr *apecommon.ChainRouterError
+			if errors.As(err, &chainRouterErr) {
+				logChainRouterError(ctx, p.logger, chainRouterErr)
+			}
 			return toStatusErr(err)
 		}
 	}
@@ -255,6 +305,7 @@ func (c *Service) Patch(ctx context.Context) (objectSvc.PatchObjectStream, error
 	streamer, err := c.next.Patch(ctx)
 
 	return &patchStreamBasicChecker{
+		logger:     c.logger,
 		apeChecker: c.apeChecker,
 		next:       streamer,
 	}, err
@@ -313,6 +364,10 @@ func (c *Service) Head(ctx context.Context, request *objectV2.HeadRequest) (*obj
 		XHeaders:       meta.GetXHeaders(),
 	})
 	if err != nil {
+		var chainRouterErr *apecommon.ChainRouterError
+		if errors.As(err, &chainRouterErr) {
+			logChainRouterError(ctx, c.logger, chainRouterErr)
+		}
 		return nil, toStatusErr(err)
 	}
 	return resp, nil
@@ -347,6 +402,10 @@ func (c *Service) Search(request *objectV2.SearchRequest, stream objectSvc.Searc
 		XHeaders:       meta.GetXHeaders(),
 	})
 	if err != nil {
+		var chainRouterErr *apecommon.ChainRouterError
+		if errors.As(err, &chainRouterErr) {
+			logChainRouterError(stream.Context(), c.logger, chainRouterErr)
+		}
 		return toStatusErr(err)
 	}
 
@@ -381,6 +440,10 @@ func (c *Service) Delete(ctx context.Context, request *objectV2.DeleteRequest) (
 		XHeaders:       meta.GetXHeaders(),
 	})
 	if err != nil {
+		var chainRouterErr *apecommon.ChainRouterError
+		if errors.As(err, &chainRouterErr) {
+			logChainRouterError(ctx, c.logger, chainRouterErr)
+		}
 		return nil, toStatusErr(err)
 	}
 
@@ -420,6 +483,10 @@ func (c *Service) GetRange(request *objectV2.GetRangeRequest, stream objectSvc.G
 		XHeaders:       meta.GetXHeaders(),
 	})
 	if err != nil {
+		var chainRouterErr *apecommon.ChainRouterError
+		if errors.As(err, &chainRouterErr) {
+			logChainRouterError(stream.Context(), c.logger, chainRouterErr)
+		}
 		return toStatusErr(err)
 	}
 
@@ -460,6 +527,10 @@ func (c *Service) GetRangeHash(ctx context.Context, request *objectV2.GetRangeHa
 	}
 
 	if err = c.apeChecker.CheckAPE(ctx, prm); err != nil {
+		var chainRouterErr *apecommon.ChainRouterError
+		if errors.As(err, &chainRouterErr) {
+			logChainRouterError(ctx, c.logger, chainRouterErr)
+		}
 		return nil, toStatusErr(err)
 	}
 	return resp, nil
@@ -495,6 +566,10 @@ func (c *Service) PutSingle(ctx context.Context, request *objectV2.PutSingleRequ
 	}
 
 	if err = c.apeChecker.CheckAPE(ctx, prm); err != nil {
+		var chainRouterErr *apecommon.ChainRouterError
+		if errors.As(err, &chainRouterErr) {
+			logChainRouterError(ctx, c.logger, chainRouterErr)
+		}
 		return nil, toStatusErr(err)
 	}