Add project field to logs in YorkieService

server/logging/logging.go

@@ -30,6 +30,9 @@ import (
 // Logger is a wrapper of zap.Logger.
 type Logger = *zap.SugaredLogger
 
+// Field is a wrapper of zap.Field.
+type Field = zap.Field
+
 var defaultLogger Logger
 var logLevel = zapcore.InfoLevel
 var loggerOnce sync.Once
@@ -57,8 +60,25 @@ func SetLogLevel(level string) error {
 }
 
 // New creates a new logger with the given configuration.
-func New(name string) Logger {
-	return newLogger(name)
+func New(name string, fields ...Field) Logger {
+	logger := newLogger(name)
+
+	if len(fields) > 0 {
+		var args = make([]interface{}, len(fields))
+		for i, field := range fields {
+			args[i] = field
+		}
+
+		logger = logger.With(args...)
+	}
+
+	return logger
+}
+
+// NewField creates a new field with the given key and value.
+func NewField(key string, value string) Field {
+	return zap.String(key, value)
+
 }
 
 // DefaultLogger returns the default logger used by Yorkie.

server/rpc/interceptors/admin.go

@@ -36,19 +36,28 @@ import (
 // ErrUnauthenticated is returned when authentication is failed.
 var ErrUnauthenticated = errors.New("authorization is not provided")
 
+func isAdminService(method string) bool {
+	return strings.HasPrefix(method, "/yorkie.v1.AdminService")
+}
+
+func isRequiredAuth(method string) bool {
+	return method != "/yorkie.v1.AdminService/LogIn" &&
+		method != "/yorkie.v1.AdminService/SignUp"
+}
+
 // AdminServiceInterceptor is an interceptor for building additional context
 // and handling authentication for AdminService.
 type AdminServiceInterceptor struct {
 	backend      *backend.Backend
-	requestID    *RequestID
+	requestID    *requestID
 	tokenManager *auth.TokenManager
 }
 
 // NewAdminServiceInterceptor creates a new instance of AdminServiceInterceptor.
 func NewAdminServiceInterceptor(be *backend.Backend, tokenManager *auth.TokenManager) *AdminServiceInterceptor {
 	return &AdminServiceInterceptor{
 		backend:      be,
-		requestID:    NewRequestID("a"),
+		requestID:    newRequestID("a"),
 		tokenManager: tokenManager,
 	}
 }
@@ -63,14 +72,9 @@ func (i *AdminServiceInterceptor) WrapUnary(next connect.UnaryFunc) connect.Unar
 			return next(ctx, req)
 		}
 
-		ctx = logging.With(ctx, logging.New(i.requestID.Next()))
-
-		if isRequiredAuth(req.Spec().Procedure) {
-			user, err := i.authenticate(ctx, req.Header())
-			if err != nil {
-				return nil, err
-			}
-			ctx = users.With(ctx, user)
+		ctx, err := i.buildContext(ctx, req.Header())
+		if err != nil {
+			return nil, err
 		}
 
 		res, err := next(ctx, req)
@@ -117,17 +121,12 @@ func (i *AdminServiceInterceptor) WrapStreamingHandler(next connect.StreamingHan
 			return next(ctx, conn)
 		}
 
-		ctx = logging.With(ctx, logging.New(i.requestID.Next()))
-
-		if isRequiredAuth(conn.Spec().Procedure) {
-			user, err := i.authenticate(ctx, conn.RequestHeader())
-			if err != nil {
-				return err
-			}
-			ctx = users.With(ctx, user)
+		ctx, err := i.buildContext(ctx, conn.RequestHeader())
+		if err != nil {
+			return err
 		}
 
-		err := next(ctx, conn)
+		err = next(ctx, conn)
 
 		// TODO(hackerwins, emplam27): Consider splitting between admin and sdk metrics.
 		sdkType, sdkVersion := connecthelper.SDKTypeAndVersion(conn.RequestHeader())
@@ -151,13 +150,22 @@ func (i *AdminServiceInterceptor) WrapStreamingHandler(next connect.StreamingHan
 	}
 }
 
-func isAdminService(method string) bool {
-	return strings.HasPrefix(method, "/yorkie.v1.AdminService")
-}
+// buildContext builds a new context with the given request header.
+func (i *AdminServiceInterceptor) buildContext(
+	ctx context.Context,
+	header http.Header,
+) (context.Context, error) {
+	if isRequiredAuth(header.Get(types.AuthorizationKey)) {
+		user, err := i.authenticate(ctx, header)
+		if err != nil {
+			return nil, err
+		}
+		ctx = users.With(ctx, user)
+	}
 
-func isRequiredAuth(method string) bool {
-	return method != "/yorkie.v1.AdminService/LogIn" &&
-		method != "/yorkie.v1.AdminService/SignUp"
+	ctx = logging.With(ctx, logging.New(i.requestID.next()))
+
+	return ctx, nil
 }
 
 // authenticate does authenticate the request.
@@ -171,6 +179,7 @@ func (i *AdminServiceInterceptor) authenticate(
 	}
 
 	// NOTE(raararaara): If the token is access token, return the user of the token.
+	// This is used for the case where the user uses dashboard or CLI.
 	claims, err := i.tokenManager.Verify(authorization)
 	if err == nil {
 		user, err := users.GetUserByName(ctx, i.backend, claims.Username)
@@ -180,6 +189,9 @@ func (i *AdminServiceInterceptor) authenticate(
 	}
 
 	// NOTE(raararaara): If the token is secret key, return the owner of the project.
+	// This is used for the case where the user uses REST API.
+	// TODO(hackerwins): In this case, attacker can hijack the project owner's identity.
+	// We need to separate project-wide API and user-wide API from AdminService.
 	project, err := projects.GetProjectFromSecretKey(ctx, i.backend, authorization)
 	if err == nil {
 		user, err := users.GetUserByID(ctx, i.backend, project.Owner)

server/rpc/interceptors/logging.go → server/rpc/interceptors/requestid.go

@@ -21,26 +21,22 @@ import (
 	"sync/atomic"
 )
 
-type RequestID struct {
+// requestID is used to generate a unique request ID.
+type requestID struct {
 	prefix string
 	id     int32
 }
 
-func NewRequestID(prefix string) *RequestID {
-	return &RequestID{
+// newRequestID creates a new requestID.
+func newRequestID(prefix string) *requestID {
+	return &requestID{
 		prefix: prefix,
 		id:     0,
 	}
 }
 
-func (r *RequestID) Next() string {
+// next generates a new request ID.
+func (r *requestID) next() string {
 	next := atomic.AddInt32(&r.id, 1)
 	return r.prefix + strconv.Itoa(int(next))
 }
-
-type reqID int32
-
-func (c *reqID) next() string {
-	next := atomic.AddInt32((*int32)(c), 1)
-	return "r" + strconv.Itoa(int(next))
-}

server/rpc/interceptors/yorkie.go

@@ -35,11 +35,15 @@ import (
 	"github.com/yorkie-team/yorkie/server/rpc/metadata"
 )
 
+func isYorkieService(method string) bool {
+	return strings.HasPrefix(method, "/yorkie.v1.YorkieService/")
+}
+
 // YorkieServiceInterceptor is an interceptor for building additional context
 // and handling authentication for YorkieService.
 type YorkieServiceInterceptor struct {
 	backend          *backend.Backend
-	requestID        *RequestID
+	requestID        *requestID
 	projectInfoCache *cache.LRUExpireCache[string, *types.Project]
 }
 
@@ -51,7 +55,7 @@ func NewYorkieServiceInterceptor(be *backend.Backend) *YorkieServiceInterceptor
 	}
 	return &YorkieServiceInterceptor{
 		backend:          be,
-		requestID:        NewRequestID("r"),
+		requestID:        newRequestID("r"),
 		projectInfoCache: projectInfoCache,
 	}
 }
@@ -106,7 +110,9 @@ func (i *YorkieServiceInterceptor) WrapStreamingClient(next connect.StreamingCli
 }
 
 // WrapStreamingHandler creates a stream server interceptor for building additional context.
-func (i *YorkieServiceInterceptor) WrapStreamingHandler(next connect.StreamingHandlerFunc) connect.StreamingHandlerFunc {
+func (i *YorkieServiceInterceptor) WrapStreamingHandler(
+	next connect.StreamingHandlerFunc,
+) connect.StreamingHandlerFunc {
 	return func(
 		ctx context.Context,
 		conn connect.StreamingHandlerConn,
@@ -144,16 +150,9 @@ func (i *YorkieServiceInterceptor) WrapStreamingHandler(next connect.StreamingHa
 	}
 }
 
-func isYorkieService(method string) bool {
-	return strings.HasPrefix(method, "/yorkie.v1.YorkieService/")
-}
-
 // buildContext builds a context data for RPC. It includes the metadata of the
 // request and the project information.
 func (i *YorkieServiceInterceptor) buildContext(ctx context.Context, header http.Header) (context.Context, error) {
-	// 00. building logger
-	ctx = logging.With(ctx, logging.New(i.requestID.Next()))
-
 	// 01. building metadata
 	md := metadata.Metadata{}
 
@@ -172,16 +171,18 @@ func (i *YorkieServiceInterceptor) buildContext(ctx context.Context, header http
 	cacheKey := md.APIKey
 
 	// 02. building project
-	if cachedProjectInfo, ok := i.projectInfoCache.Get(cacheKey); ok {
-		ctx = projects.With(ctx, cachedProjectInfo)
-	} else {
-		project, err := projects.GetProjectFromAPIKey(ctx, i.backend, md.APIKey)
+	if _, ok := i.projectInfoCache.Get(cacheKey); !ok {
+		prj, err := projects.GetProjectFromAPIKey(ctx, i.backend, md.APIKey)
 		if err != nil {
 			return nil, connecthelper.ToStatusError(err)
 		}
-		i.projectInfoCache.Add(cacheKey, project, i.backend.Config.ParseProjectInfoCacheTTL())
-		ctx = projects.With(ctx, project)
+		i.projectInfoCache.Add(cacheKey, prj, i.backend.Config.ParseProjectInfoCacheTTL())
 	}
+	project, _ := i.projectInfoCache.Get(cacheKey)
+	ctx = projects.With(ctx, project)
+
+	// 03. building logger
+	ctx = logging.With(ctx, logging.New(i.requestID.next(), logging.NewField("prj", project.Name)))
 
 	return ctx, nil
 }