feature/318_add_logs #319

Merged
alexvanin merged 9 commits from dkirillov/frostfs-s3-gw:feature/318_add_logs into master 2024-09-04 19:51:13 +00:00
10 changed files with 93 additions and 52 deletions

View file

@ -94,12 +94,12 @@ func New(creds tokens.Credentials, prefixes []string) *Center {
func (c *Center) parseAuthHeader(header string) (*AuthHeader, error) {
submatches := c.reg.GetSubmatches(header)
if len(submatches) != authHeaderPartsNum {
return nil, apiErrors.GetAPIError(apiErrors.ErrAuthorizationHeaderMalformed)
return nil, fmt.Errorf("%w: %s", apiErrors.GetAPIError(apiErrors.ErrAuthorizationHeaderMalformed), header)
}
accessKey := strings.Split(submatches["access_key_id"], "0")
if len(accessKey) != accessKeyPartsNum {
return nil, apiErrors.GetAPIError(apiErrors.ErrInvalidAccessKeyID)
return nil, fmt.Errorf("%w: %s", apiErrors.GetAPIError(apiErrors.ErrInvalidAccessKeyID), accessKey)
}
signedFields := strings.Split(submatches["signed_header_fields"], ";")
@ -114,11 +114,12 @@ func (c *Center) parseAuthHeader(header string) (*AuthHeader, error) {
}, nil
}
func (a *AuthHeader) getAddress() (oid.Address, error) {
func getAddress(accessKeyID string) (oid.Address, error) {
var addr oid.Address
if err := addr.DecodeString(strings.ReplaceAll(a.AccessKeyID, "0", "/")); err != nil {
return addr, apiErrors.GetAPIError(apiErrors.ErrInvalidAccessKeyID)
if err := addr.DecodeString(strings.ReplaceAll(accessKeyID, "0", "/")); err != nil {
return addr, fmt.Errorf("%w: %s", apiErrors.GetAPIError(apiErrors.ErrInvalidAccessKeyID), accessKeyID)
}
return addr, nil
}
@ -161,7 +162,7 @@ func (c *Center) Authenticate(r *http.Request) (*middleware.Box, error) {
if strings.HasPrefix(r.Header.Get(ContentTypeHdr), "multipart/form-data") {
return c.checkFormData(r)
}
return nil, middleware.ErrNoAuthorizationHeader
return nil, fmt.Errorf("%w: %v", middleware.ErrNoAuthorizationHeader, authHeaderField)
}
authHdr, err = c.parseAuthHeader(authHeaderField[0])
if err != nil {
@ -176,18 +177,18 @@ func (c *Center) Authenticate(r *http.Request) (*middleware.Box, error) {
return nil, fmt.Errorf("failed to parse x-amz-date header field: %w", err)
}
if err := c.checkAccessKeyID(authHdr.AccessKeyID); err != nil {
if err = c.checkAccessKeyID(authHdr.AccessKeyID); err != nil {
return nil, err
}
addr, err := authHdr.getAddress()
addr, err := getAddress(authHdr.AccessKeyID)
if err != nil {
return nil, err
}
box, err := c.cli.GetBox(r.Context(), addr)
if err != nil {
return nil, fmt.Errorf("get box: %w", err)
return nil, fmt.Errorf("get box '%s': %w", addr, err)
}
if err = checkFormatHashContentSHA256(r.Header.Get(AmzContentSHA256)); err != nil {
@ -218,10 +219,11 @@ func checkFormatHashContentSHA256(hash string) error {
if !IsStandardContentSHA256(hash) {
hashBinary, err := hex.DecodeString(hash)
if err != nil {
return apiErrors.GetAPIError(apiErrors.ErrContentSHA256Mismatch)
return fmt.Errorf("%w: decode hash: %s: %s", apiErrors.GetAPIError(apiErrors.ErrContentSHA256Mismatch),
hash, err.Error())
}
if len(hashBinary) != sha256.Size && len(hash) != 0 {
return apiErrors.GetAPIError(apiErrors.ErrContentSHA256Mismatch)
return fmt.Errorf("%w: invalid hash size %d", apiErrors.GetAPIError(apiErrors.ErrContentSHA256Mismatch), len(hashBinary))
}
}
@ -239,12 +241,12 @@ func (c Center) checkAccessKeyID(accessKeyID string) error {
}
}
return apiErrors.GetAPIError(apiErrors.ErrAccessDenied)
return fmt.Errorf("%w: accesskeyID prefix isn't allowed", apiErrors.GetAPIError(apiErrors.ErrAccessDenied))
}
func (c *Center) checkFormData(r *http.Request) (*middleware.Box, error) {
if err := r.ParseMultipartForm(maxFormSizeMemory); err != nil {
return nil, apiErrors.GetAPIError(apiErrors.ErrInvalidArgument)
return nil, fmt.Errorf("%w: parse multipart form with max size %d", apiErrors.GetAPIError(apiErrors.ErrInvalidArgument), maxFormSizeMemory)
}
if err := prepareForm(r.MultipartForm); err != nil {
@ -253,12 +255,13 @@ func (c *Center) checkFormData(r *http.Request) (*middleware.Box, error) {
policy := MultipartFormValue(r, "policy")
if policy == "" {
return nil, middleware.ErrNoAuthorizationHeader
return nil, fmt.Errorf("%w: missing policy", middleware.ErrNoAuthorizationHeader)
}
submatches := c.postReg.GetSubmatches(MultipartFormValue(r, "x-amz-credential"))
creds := MultipartFormValue(r, "x-amz-credential")
submatches := c.postReg.GetSubmatches(creds)
if len(submatches) != 4 {
return nil, apiErrors.GetAPIError(apiErrors.ErrAuthorizationHeaderMalformed)
return nil, fmt.Errorf("%w: %s", apiErrors.GetAPIError(apiErrors.ErrAuthorizationHeaderMalformed), creds)
}
signatureDateTime, err := time.Parse("20060102T150405Z", MultipartFormValue(r, "x-amz-date"))
@ -266,22 +269,24 @@ func (c *Center) checkFormData(r *http.Request) (*middleware.Box, error) {
return nil, fmt.Errorf("failed to parse x-amz-date field: %w", err)
}
var addr oid.Address
if err = addr.DecodeString(strings.ReplaceAll(submatches["access_key_id"], "0", "/")); err != nil {
return nil, apiErrors.GetAPIError(apiErrors.ErrInvalidAccessKeyID)
addr, err := getAddress(submatches["access_key_id"])
if err != nil {
return nil, err
}
box, err := c.cli.GetBox(r.Context(), addr)
if err != nil {
return nil, fmt.Errorf("get box: %w", err)
return nil, fmt.Errorf("get box '%s': %w", addr, err)
}
secret := box.Gate.SecretKey
service, region := submatches["service"], submatches["region"]
signature := signStr(secret, service, region, signatureDateTime, policy)
if signature != MultipartFormValue(r, "x-amz-signature") {
return nil, apiErrors.GetAPIError(apiErrors.ErrSignatureDoesNotMatch)
reqSignature := MultipartFormValue(r, "x-amz-signature")
if signature != reqSignature {
return nil, fmt.Errorf("%w: %s != %s", apiErrors.GetAPIError(apiErrors.ErrSignatureDoesNotMatch),
reqSignature, signature)
}
return &middleware.Box{AccessBox: box}, nil
@ -317,10 +322,12 @@ func (c *Center) checkSign(authHeader *AuthHeader, box *accessbox.Box, request *
if authHeader.IsPresigned {
now := time.Now()
if signatureDateTime.Add(authHeader.Expiration).Before(now) {
return apiErrors.GetAPIError(apiErrors.ErrExpiredPresignRequest)
return fmt.Errorf("%w: expired: now %s, signature %s", apiErrors.GetAPIError(apiErrors.ErrExpiredPresignRequest),
now.Format(time.RFC3339), signatureDateTime.Format(time.RFC3339))
}
if now.Before(signatureDateTime) {
return apiErrors.GetAPIError(apiErrors.ErrBadRequest)
return fmt.Errorf("%w: signature time from the future: now %s, signature %s", apiErrors.GetAPIError(apiErrors.ErrBadRequest),
now.Format(time.RFC3339), signatureDateTime.Format(time.RFC3339))
}
if _, err := signer.Presign(request, nil, authHeader.Service, authHeader.Region, authHeader.Expiration, signatureDateTime); err != nil {
return fmt.Errorf("failed to pre-sign temporary HTTP request: %w", err)
@ -334,7 +341,8 @@ func (c *Center) checkSign(authHeader *AuthHeader, box *accessbox.Box, request *
}
if authHeader.SignatureV4 != signature {
return apiErrors.GetAPIError(apiErrors.ErrSignatureDoesNotMatch)
return fmt.Errorf("%w: %s != %s: headers %v", apiErrors.GetAPIError(apiErrors.ErrSignatureDoesNotMatch),
authHeader.SignatureV4, signature, authHeader.SignedFields)
}
return nil

View file

@ -45,7 +45,7 @@ func TestAuthHeaderParse(t *testing.T) {
},
} {
authHeader, err := center.parseAuthHeader(tc.header)
require.Equal(t, tc.err, err, tc.header)
require.ErrorIs(t, err, tc.err, tc.header)
require.Equal(t, tc.expected, authHeader, tc.header)
}
}
@ -82,8 +82,8 @@ func TestAuthHeaderGetAddress(t *testing.T) {
err: defaulErr,
},
} {
_, err := tc.authHeader.getAddress()
require.Equal(t, tc.err, err, tc.authHeader.AccessKeyID)
_, err := getAddress(tc.authHeader.AccessKeyID)
require.ErrorIs(t, err, tc.err, tc.authHeader.AccessKeyID)
}
}
@ -141,7 +141,7 @@ func TestCheckFormatContentSHA256(t *testing.T) {
} {
t.Run(tc.name, func(t *testing.T) {
err := checkFormatHashContentSHA256(tc.hash)
require.Equal(t, tc.error, err)
require.ErrorIs(t, err, tc.error)
})
}
}

View file

@ -7,6 +7,7 @@ import (
"encoding/hex"
"encoding/json"
"encoding/xml"
stderrors "errors"
"fmt"
"io"
"net"
@ -628,11 +629,21 @@ func checkPostPolicy(r *http.Request, reqInfo *middleware.ReqInfo, metadata map[
policy.empty = false
}
if r.MultipartForm == nil {
return nil, stderrors.New("empty multipart form")
}
for key, v := range r.MultipartForm.Value {
value := v[0]
if key == "file" || key == "policy" || key == "x-amz-signature" || strings.HasPrefix(key, "x-ignore-") {
continue
}
if len(v) != 1 {
return nil, fmt.Errorf("empty multipart value for key '%s'", key)
}
value := v[0]
if err := policy.CheckField(key, value); err != nil {
return nil, fmt.Errorf("'%s' form field doesn't match the policy: %w", key, err)
}

View file

@ -2,14 +2,15 @@ package middleware
import (
"crypto/elliptic"
stderrors "errors"
"errors"
"fmt"
"net/http"
"time"
"git.frostfs.info/TrueCloudLab/frostfs-api-go/v2/acl"
"git.frostfs.info/TrueCloudLab/frostfs-s3-gw/api/errors"
apiErrors "git.frostfs.info/TrueCloudLab/frostfs-s3-gw/api/errors"
"git.frostfs.info/TrueCloudLab/frostfs-s3-gw/creds/accessbox"
frostfsErrors "git.frostfs.info/TrueCloudLab/frostfs-s3-gw/internal/frostfs/errors"
"git.frostfs.info/TrueCloudLab/frostfs-s3-gw/internal/logs"
"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/bearer"
"github.com/nspcc-dev/neo-go/pkg/crypto/keys"
@ -40,7 +41,7 @@ type (
)
// ErrNoAuthorizationHeader is returned for unauthenticated requests.
var ErrNoAuthorizationHeader = stderrors.New("no authorization header")
var ErrNoAuthorizationHeader = errors.New("no authorization header")
func Auth(center Center, log *zap.Logger) Func {
return func(h http.Handler) http.Handler {
@ -50,12 +51,13 @@ func Auth(center Center, log *zap.Logger) Func {
reqInfo.User = "anon"
box, err := center.Authenticate(r)
if err != nil {
if err == ErrNoAuthorizationHeader {
reqLogOrDefault(ctx, log).Debug(logs.CouldntReceiveAccessBoxForGateKeyRandomKeyWillBeUsed)
if errors.Is(err, ErrNoAuthorizationHeader) {
reqLogOrDefault(ctx, log).Debug(logs.CouldntReceiveAccessBoxForGateKeyRandomKeyWillBeUsed, zap.Error(err))
} else {
reqLogOrDefault(ctx, log).Error(logs.FailedToPassAuthentication, zap.Error(err))
if _, ok := err.(errors.Error); !ok {
err = errors.GetAPIError(errors.ErrAccessDenied)
err = frostfsErrors.UnwrapErr(err)
if _, ok := err.(apiErrors.Error); !ok {
err = apiErrors.GetAPIError(apiErrors.ErrAccessDenied)
}
WriteErrorResponse(w, GetReqInfo(r.Context()), err)
return
@ -70,6 +72,7 @@ func Auth(center Center, log *zap.Logger) Func {
if box.AccessBox.Gate.BearerToken != nil {
reqInfo.User = bearer.ResolveIssuer(*box.AccessBox.Gate.BearerToken).String()
}
reqLogOrDefault(ctx, log).Debug(logs.SuccessfulAuth, zap.String("accessKeyID", box.AuthHeaders.AccessKeyID))
}
h.ServeHTTP(w, r.WithContext(ctx))

View file

@ -54,7 +54,7 @@ func PolicyCheck(cfg PolicyConfig) Func {
func policyCheck(r *http.Request, cfg PolicyConfig) error {
reqType, bktName, objName := getBucketObject(r, cfg.Domains)
req, err := getPolicyRequest(r, cfg.FrostfsID, reqType, bktName, objName)
req, err := getPolicyRequest(r, cfg.FrostfsID, reqType, bktName, objName, cfg.Log)
if err != nil {
return err
}
@ -103,7 +103,7 @@ func isAPEBehavior(ctx context.Context, req *testutil.Request, cfg PolicyConfig,
return bktInfo.APEEnabled, nil
}
func getPolicyRequest(r *http.Request, frostfsid FrostFSIDInformer, reqType ReqType, bktName string, objName string) (*testutil.Request, error) {
func getPolicyRequest(r *http.Request, frostfsid FrostFSIDInformer, reqType ReqType, bktName string, objName string, log *zap.Logger) (*testutil.Request, error) {
var (
owner string
groups []string
@ -133,6 +133,9 @@ func getPolicyRequest(r *http.Request, frostfsid FrostFSIDInformer, reqType ReqT
res = fmt.Sprintf(s3.ResourceFormatS3Bucket, bktName)
}
reqLogOrDefault(r.Context(), log).Debug(logs.PolicyRequest, zap.String("action", op),
zap.String("resource", res), zap.String("owner", owner))
return testutil.NewRequest(op, testutil.NewResource(res, nil),
map[string]string{
s3.PropertyKeyOwner: owner,
@ -290,7 +293,7 @@ func determineBucketOperation(r *http.Request) string {
}
}
return ""
return "UnmatchedBucketOperation"
}
func determineObjectOperation(r *http.Request) string {
@ -354,12 +357,12 @@ func determineObjectOperation(r *http.Request) string {
}
}
return ""
return "UnmatchedObjectOperation"
}
func determineGeneralOperation(r *http.Request) string {
if r.Method == http.MethodGet {
return ListBucketsOperation
}
return ""
return "UnmatchedOperation"
}

View file

@ -222,7 +222,7 @@ func Request(log *zap.Logger, settings RequestSettings) Func {
r = r.WithContext(SetReqLogger(r.Context(), reqLogger))
reqLogger.Info(logs.RequestStart, zap.String("host", r.Host),
zap.String("remote_host", reqInfo.RemoteHost))
zap.String("remote_host", reqInfo.RemoteHost), zap.String("namespace", reqInfo.Namespace))
// continue execution
h.ServeHTTP(w, r)
@ -239,8 +239,10 @@ func AddBucketName(l *zap.Logger) Func {
reqInfo := GetReqInfo(ctx)
reqInfo.BucketName = chi.URLParam(r, BucketURLPrm)
reqLogger := reqLogOrDefault(ctx, l)
r = r.WithContext(SetReqLogger(ctx, reqLogger.With(zap.String("bucket", reqInfo.BucketName))))
if reqInfo.BucketName != "" {
reqLogger := reqLogOrDefault(ctx, l)
r = r.WithContext(SetReqLogger(ctx, reqLogger.With(zap.String("bucket", reqInfo.BucketName))))
}
h.ServeHTTP(w, r)
})
@ -270,7 +272,9 @@ func AddObjectName(l *zap.Logger) Func {
}
}
r = r.WithContext(SetReqLogger(ctx, reqLogger.With(zap.String("object", reqInfo.ObjectName))))
if reqInfo.ObjectName != "" {
r = r.WithContext(SetReqLogger(ctx, reqLogger.With(zap.String("object", reqInfo.ObjectName))))
}
h.ServeHTTP(w, r)
})

View file

@ -312,12 +312,20 @@ func LogSuccessResponse(l *zap.Logger) Func {
reqLogger := reqLogOrDefault(ctx, l)
reqInfo := GetReqInfo(ctx)
fields := []zap.Field{
zap.String("method", reqInfo.API),
zap.String("bucket", reqInfo.BucketName),
zap.String("object", reqInfo.ObjectName),
fields := make([]zap.Field, 0, 6)
fields = append(fields,
zap.Int("status", lw.statusCode),
zap.String("description", http.StatusText(lw.statusCode))}
zap.String("description", http.StatusText(lw.statusCode)),
zap.String("method", reqInfo.API),
)
if reqInfo.BucketName != "" {
fields = append(fields, zap.String("bucket", reqInfo.BucketName))
}
if reqInfo.ObjectName != "" {
fields = append(fields, zap.String("object", reqInfo.ObjectName))
}
if traceID, err := trace.TraceIDFromHex(reqInfo.TraceID); err == nil && traceID.IsValid() {
fields = append(fields, zap.String("trace_id", reqInfo.TraceID))
}

View file

@ -148,6 +148,7 @@ func NewRouter(cfg Config) *chi.Mux {
defaultRouter := chi.NewRouter()
defaultRouter.Mount(fmt.Sprintf("/{%s}", s3middleware.BucketURLPrm), bucketRouter(cfg.Handler, cfg.Log))
defaultRouter.Get("/", named("ListBuckets", cfg.Handler.ListBucketsHandler))
attachErrorHandler(defaultRouter)
hr := NewHostBucketRouter("bucket")
hr.Default(defaultRouter)
@ -182,7 +183,7 @@ func errorResponseHandler(w http.ResponseWriter, r *http.Request) {
})
if log := s3middleware.GetReqLog(ctx); log != nil {
log.Error(logs.RequestUnmatched, zap.String("method", reqInfo.API))
log.Error(logs.RequestUnmatched, zap.String("method", reqInfo.API), zap.String("http method", r.Method), zap.String("url", r.RequestURI))
}
}

View file

@ -44,6 +44,7 @@ func (c *centerMock) Authenticate(*http.Request) (*middleware.Box, error) {
}
return &middleware.Box{
AuthHeaders: &middleware.AuthHeader{},
AccessBox: &accessbox.Box{
Gate: &accessbox.GateData{
BearerToken: token,

View file

@ -146,4 +146,6 @@ const (
BucketOwnerKeyIsMissing = "bucket owner key is missing"
SettingsNodeInvalidOwnerKey = "settings node: invalid owner key"
FailedToSendTransaction = "failed to send transaction"
SuccessfulAuth = "successful auth"
PolicyRequest = "policy request"
)