add facade and entity to logs (#1450)

* add facade and entity to logs * add info logs for jimm's groups and roles methods
canonical · Nov 25, 2024 · ee16e51 · ee16e51
1 parent 03071b0
commit ee16e51
Show file tree

Hide file tree

Showing 5 changed files with 53 additions and 20 deletions.
diff --git a/internal/jimm/model.go b/internal/jimm/model.go
@@ -553,6 +553,7 @@ func (b *modelBuilder) JujuModelInfo() *jujuparams.ModelInfo {
 // AddModel adds the specified model to JIMM.
 func (j *JIMM) AddModel(ctx context.Context, user *openfga.User, args *ModelCreateArgs) (_ *jujuparams.ModelInfo, err error) {
 	const op = errors.Op("jimm.AddModel")
+	zapctx.Info(ctx, string(op))
 
 	owner, err := dbmodel.NewIdentity(args.Owner.Id())
 	if err != nil {
@@ -719,6 +720,7 @@ func (j *JIMM) addModelPermissions(ctx context.Context, owner *openfga.User, mt
 // CodeUnauthorized.
 func (j *JIMM) ModelInfo(ctx context.Context, user *openfga.User, mt names.ModelTag) (*jujuparams.ModelInfo, error) {
 	const op = errors.Op("jimm.ModelInfo")
+	zapctx.Info(ctx, string(op))
 
 	var m dbmodel.Model
 	m.SetTag(mt)
@@ -750,6 +752,7 @@ func (j *JIMM) ModelInfo(ctx context.Context, user *openfga.User, mt names.Model
 // information from JIMM where JIMM specific information should be used.
 func (j *JIMM) mergeModelInfo(ctx context.Context, user *openfga.User, modelInfo *jujuparams.ModelInfo, jimmModel dbmodel.Model) (*jujuparams.ModelInfo, error) {
 	const op = errors.Op("jimm.mergeModelInfo")
+	zapctx.Info(ctx, string(op))
 
 	jimmSummary := jimmModel.ToJujuModelSummary()
 	modelInfo.CloudCredentialTag = jimmSummary.CloudCredentialTag
@@ -816,6 +819,7 @@ func (j *JIMM) mergeModelInfo(ctx context.Context, user *openfga.User, modelInfo
 // then the returned error will have the code CodeUnauthorized.
 func (j *JIMM) ModelStatus(ctx context.Context, user *openfga.User, mt names.ModelTag) (*jujuparams.ModelStatus, error) {
 	const op = errors.Op("jimm.ModelStatus")
+	zapctx.Info(ctx, string(op))
 
 	var ms jujuparams.ModelStatus
 	err := j.doModelAdmin(ctx, user, mt, func(_ *dbmodel.Model, api API) error {
@@ -839,6 +843,7 @@ func (j *JIMM) ModelStatus(ctx context.Context, user *openfga.User, mt names.Mod
 // function should not update the database.
 func (j *JIMM) ForEachUserModel(ctx context.Context, user *openfga.User, f func(*dbmodel.Model, jujuparams.UserAccessPermission) error) error {
 	const op = errors.Op("jimm.ForEachUserModel")
+	zapctx.Info(ctx, string(op))
 
 	errStop := errors.E("stop")
 	var iterErr error
@@ -877,6 +882,7 @@ func (j *JIMM) ForEachUserModel(ctx context.Context, user *openfga.User, f func(
 // immediately. The given function should not update the database.
 func (j *JIMM) ForEachModel(ctx context.Context, user *openfga.User, f func(*dbmodel.Model, jujuparams.UserAccessPermission) error) error {
 	const op = errors.Op("jimm.ForEachModel")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return errors.E(op, errors.CodeUnauthorized, "unauthorized")
@@ -908,6 +914,7 @@ func (j *JIMM) ForEachModel(ctx context.Context, user *openfga.User, f func(*dbm
 // is returned.
 func (j *JIMM) GrantModelAccess(ctx context.Context, user *openfga.User, mt names.ModelTag, ut names.UserTag, access jujuparams.UserAccessPermission) error {
 	const op = errors.Op("jimm.GrantModelAccess")
+	zapctx.Info(ctx, string(op))
 
 	targetRelation, err := ToModelRelation(string(access))
 	if err != nil {
@@ -980,6 +987,7 @@ func (j *JIMM) GrantModelAccess(ctx context.Context, user *openfga.User, mt name
 // then an error with the code CodeUnauthorized is returned.
 func (j *JIMM) RevokeModelAccess(ctx context.Context, user *openfga.User, mt names.ModelTag, ut names.UserTag, access jujuparams.UserAccessPermission) error {
 	const op = errors.Op("jimm.RevokeModelAccess")
+	zapctx.Info(ctx, string(op))
 
 	targetRelation, err := ToModelRelation(string(access))
 	if err != nil {
@@ -1068,6 +1076,7 @@ func (j *JIMM) RevokeModelAccess(ctx context.Context, user *openfga.User, mt nam
 // the juju API will not have it's code masked.
 func (j *JIMM) DestroyModel(ctx context.Context, user *openfga.User, mt names.ModelTag, destroyStorage, force *bool, maxWait, timeout *time.Duration) error {
 	const op = errors.Op("jimm.DestroyModel")
+	zapctx.Info(ctx, string(op))
 
 	err := j.doModelAdmin(ctx, user, mt, func(m *dbmodel.Model, api API) error {
 		if err := api.DestroyModel(ctx, mt, destroyStorage, force, maxWait, timeout); err != nil {
@@ -1099,6 +1108,7 @@ func (j *JIMM) DestroyModel(ctx context.Context, user *openfga.User, mt names.Mo
 // error with the code CodeUnauthorized is returned.
 func (j *JIMM) DumpModel(ctx context.Context, user *openfga.User, mt names.ModelTag, simplified bool) (string, error) {
 	const op = errors.Op("jimm.DumpModel")
+	zapctx.Info(ctx, string(op))
 
 	var dump string
 	err := j.doModelAdmin(ctx, user, mt, func(m *dbmodel.Model, api API) error {
@@ -1117,6 +1127,7 @@ func (j *JIMM) DumpModel(ctx context.Context, user *openfga.User, mt names.Model
 // admin an error with the code CodeUnauthorized is returned.
 func (j *JIMM) DumpModelDB(ctx context.Context, user *openfga.User, mt names.ModelTag) (map[string]interface{}, error) {
 	const op = errors.Op("jimm.DumpModelDB")
+	zapctx.Info(ctx, string(op))
 
 	var dump map[string]interface{}
 	err := j.doModelAdmin(ctx, user, mt, func(m *dbmodel.Model, api API) error {
@@ -1138,6 +1149,7 @@ func (j *JIMM) DumpModelDB(ctx context.Context, user *openfga.User, mt names.Mod
 // CodeNotImplemented error code will be propagated back to the client.
 func (j *JIMM) ValidateModelUpgrade(ctx context.Context, user *openfga.User, mt names.ModelTag, force bool) error {
 	const op = errors.Op("jimm.ValidateModelUpgrade")
+	zapctx.Info(ctx, string(op))
 
 	err := j.doModelAdmin(ctx, user, mt, func(_ *dbmodel.Model, api API) error {
 		return api.ValidateModelUpgrade(ctx, mt, force)
@@ -1172,6 +1184,7 @@ func (j *JIMM) GetUserModelAccess(ctx context.Context, user *openfga.User, model
 
 func (j *JIMM) doModel(ctx context.Context, user *openfga.User, mt names.ModelTag, access string, f func(*dbmodel.Model, API) error) error {
 	const op = errors.Op("jimm.doModel")
+	zapctx.Info(ctx, string(op))
 
 	var m dbmodel.Model
 	m.SetTag(mt)
@@ -1220,6 +1233,7 @@ var allowedModelAccess = map[string]map[string]bool{
 // the controller and the local database.
 func (j *JIMM) ChangeModelCredential(ctx context.Context, user *openfga.User, modelTag names.ModelTag, cloudCredentialTag names.CloudCredentialTag) error {
 	const op = errors.Op("jimm.ChangeModelCredential")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin && user.Tag() != cloudCredentialTag.Owner() {
 		return errors.E(op, errors.CodeUnauthorized, "unauthorized")

diff --git a/internal/jimm/role/role.go b/internal/jimm/role/role.go
@@ -4,7 +4,6 @@ package role
 
 import (
 	"context"
-	"fmt"
 
 	"github.com/juju/zaputil/zapctx"
 
@@ -34,8 +33,8 @@ func NewRoleManager(store *db.Database, authSvc *openfga.OFGAClient) (*roleManag
 
 // AddRole adds a role to JIMM.
 func (rm *roleManager) AddRole(ctx context.Context, user *openfga.User, roleName string) (*dbmodel.RoleEntry, error) {
-	const op = errors.Op("roleManager.AddRole")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.AddRole")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return nil, errors.E(op, errors.CodeUnauthorized, "unauthorized")
@@ -50,24 +49,24 @@ func (rm *roleManager) AddRole(ctx context.Context, user *openfga.User, roleName
 
 // GetRoleByUUID returns a role based on the provided UUID.
 func (rm *roleManager) GetRoleByUUID(ctx context.Context, user *openfga.User, uuid string) (*dbmodel.RoleEntry, error) {
-	const op = errors.Op("roleManager.GetRoleByUUID")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.GetRoleByUUID")
+	zapctx.Info(ctx, string(op))
 
 	return rm.getRole(ctx, user, &dbmodel.RoleEntry{UUID: uuid})
 }
 
 // GetRoleByName returns a role based on the provided name.
 func (rm *roleManager) GetRoleByName(ctx context.Context, user *openfga.User, name string) (*dbmodel.RoleEntry, error) {
-	const op = errors.Op("roleManager.GetRoleByName")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.GetRoleByName")
+	zapctx.Info(ctx, string(op))
 
 	return rm.getRole(ctx, user, &dbmodel.RoleEntry{Name: name})
 }
 
 // RemoveRole removes the role from JIMM in both the store and authorisation store.
 func (rm *roleManager) RemoveRole(ctx context.Context, user *openfga.User, roleName string) error {
-	const op = errors.Op("roleManager.RemoveRole")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.RemoveRole")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return errors.E(op, errors.CodeUnauthorized, "unauthorized")
@@ -97,8 +96,8 @@ func (rm *roleManager) RemoveRole(ctx context.Context, user *openfga.User, roleN
 
 // RenameRole renames a role in JIMM's DB.
 func (rm *roleManager) RenameRole(ctx context.Context, user *openfga.User, uuid, newName string) error {
-	const op = errors.Op("roleManager.RenameRole")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.RenameRole")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return errors.E(op, errors.CodeUnauthorized, "unauthorized")
@@ -115,8 +114,8 @@ func (rm *roleManager) RenameRole(ctx context.Context, user *openfga.User, uuid,
 // ListRoles returns a list of roles known to JIMM.
 // `match` will filter the list fuzzy matching role's name or uuid.
 func (rm *roleManager) ListRoles(ctx context.Context, user *openfga.User, pagination pagination.LimitOffsetPagination, match string) ([]dbmodel.RoleEntry, error) {
-	const op = errors.Op("roleManager.ListRoles")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.ListRoles")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return nil, errors.E(op, errors.CodeUnauthorized, "unauthorized")
@@ -131,8 +130,8 @@ func (rm *roleManager) ListRoles(ctx context.Context, user *openfga.User, pagina
 
 // CountRoles returns the number of roles that exist.
 func (rm *roleManager) CountRoles(ctx context.Context, user *openfga.User) (int, error) {
-	const op = errors.Op("roleManager.CountRoles")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.CountRoles")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return 0, errors.E(op, errors.CodeUnauthorized, "unauthorized")
@@ -146,8 +145,8 @@ func (rm *roleManager) CountRoles(ctx context.Context, user *openfga.User) (int,
 
 // getRole returns a role based on the provided UUID or name.
 func (rm *roleManager) getRole(ctx context.Context, user *openfga.User, role *dbmodel.RoleEntry) (*dbmodel.RoleEntry, error) {
-	const op = errors.Op("roleManager.getRole")
-	zapctx.Debug(ctx, fmt.Sprintf("Running %s", op))
+	const op = errors.Op("role.getRole")
+	zapctx.Info(ctx, string(op))
 
 	if !user.JimmAdmin {
 		return nil, errors.E(op, errors.CodeUnauthorized, "unauthorized")

diff --git a/internal/jujuapi/modelmanager.go b/internal/jujuapi/modelmanager.go
@@ -9,6 +9,8 @@ import (
 
 	jujuparams "github.com/juju/juju/rpc/params"
 	"github.com/juju/names/v5"
+	"github.com/juju/zaputil/zapctx"
+	"go.uber.org/zap"
 
 	"github.com/canonical/jimm/v3/internal/dbmodel"
 	"github.com/canonical/jimm/v3/internal/errors"
@@ -89,6 +91,7 @@ func (r *controllerRoot) DumpModels(ctx context.Context, args jujuparams.DumpMod
 	results := make([]jujuparams.StringResult, len(args.Entities))
 	for i, ent := range args.Entities {
 		mt, err := names.ParseModelTag(ent.Tag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", mt.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err, errors.CodeBadRequest))
 		}
@@ -144,6 +147,7 @@ func (r *controllerRoot) ModelInfo(ctx context.Context, args jujuparams.Entities
 	results := make([]jujuparams.ModelInfoResult, len(args.Entities))
 	for i, arg := range args.Entities {
 		mt, err := names.ParseModelTag(arg.Tag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", mt.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err, errors.CodeBadRequest))
 			continue
@@ -200,6 +204,7 @@ func (r *controllerRoot) DestroyModels(ctx context.Context, args jujuparams.Dest
 
 	for i, model := range args.Models {
 		mt, err := names.ParseModelTag(model.ModelTag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", mt.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err, errors.CodeBadRequest))
 			continue
@@ -228,6 +233,7 @@ func (r *controllerRoot) ModifyModelAccess(ctx context.Context, args jujuparams.
 	results := make([]jujuparams.ErrorResult, len(args.Changes))
 	for i, change := range args.Changes {
 		mt, err := names.ParseModelTag(change.ModelTag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", mt.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err, errors.CodeBadRequest))
 			continue
@@ -266,6 +272,7 @@ func (r *controllerRoot) DumpModelsDB(ctx context.Context, args jujuparams.Entit
 	results := make([]jujuparams.MapResult, len(args.Entities))
 	for i, ent := range args.Entities {
 		mt, err := names.ParseModelTag(ent.Tag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", mt.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err, errors.CodeBadRequest))
 		}
@@ -283,6 +290,7 @@ func (r *controllerRoot) DumpModelsDB(ctx context.Context, args jujuparams.Entit
 // ChangeModelCredential method.
 func (r *controllerRoot) ChangeModelCredential(ctx context.Context, args jujuparams.ChangeModelCredentialsParams) (jujuparams.ErrorResults, error) {
 	ctx, cancel := context.WithTimeout(ctx, requestTimeout)
+
 	defer cancel()
 	results := make([]jujuparams.ErrorResult, len(args.Models))
 	for i, arg := range args.Models {
@@ -297,6 +305,7 @@ func (r *controllerRoot) changeModelCredential(ctx context.Context, arg jujupara
 	const op = errors.Op("jujuapi.ChangeModelCredential")
 
 	mt, err := names.ParseModelTag(arg.ModelTag)
+	ctx = zapctx.WithFields(ctx, zap.String("entity", mt.String()))
 	if err != nil {
 		return errors.E(op, err, errors.CodeBadRequest)
 	}
@@ -321,6 +330,7 @@ func (r *controllerRoot) ValidateModelUpgrades(ctx context.Context, args jujupar
 	results := make([]jujuparams.ErrorResult, len(args.Models))
 	for i, arg := range args.Models {
 		modelTag, err := names.ParseModelTag(arg.ModelTag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", modelTag.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err, errors.CodeBadRequest))
 			continue
@@ -339,6 +349,7 @@ func (r *controllerRoot) SetModelDefaults(ctx context.Context, args jujuparams.S
 	results := make([]jujuparams.ErrorResult, len(args.Config))
 	for i, config := range args.Config {
 		cloudTag, err := names.ParseCloudTag(config.CloudTag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", cloudTag.String()))
 		if err != nil {
 			results[i].Error = mapError(errors.E(op, err))
 			continue
@@ -356,6 +367,7 @@ func (r *controllerRoot) UnsetModelDefaults(ctx context.Context, args jujuparams
 	results := make([]jujuparams.ErrorResult, len(args.Keys))
 	for i, key := range args.Keys {
 		cloudTag, err := names.ParseCloudTag(key.CloudTag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", cloudTag.String()))
 		if err != nil {
 			results[i].Error = mapError(err)
 			continue
@@ -377,6 +389,7 @@ func (r *controllerRoot) ModelDefaultsForClouds(ctx context.Context, args jujupa
 	result.Results = make([]jujuparams.ModelDefaultsResult, len(args.Entities))
 	for i, entity := range args.Entities {
 		cloudTag, err := names.ParseCloudTag(entity.Tag)
+		ctx = zapctx.WithFields(ctx, zap.String("entity", cloudTag.String()))
 		if err != nil {
 			result.Results[i].Error = mapError(errors.E(op, err))
 			continue

diff --git a/internal/jujuapi/rpc/root.go b/internal/jujuapi/rpc/root.go
@@ -50,6 +50,9 @@ func (r *Root) FindMethod(rootName string, version int, methodName string) (rpcr
 		return rootMethodCaller{
 			MethodCaller: caller,
 			r:            r,
+			methodName:   methodName,
+			facadeName:   rootName,
+			version:      version,
 		}, nil
 	}
 	return nil, &rpcreflect.CallNotImplementedError{
@@ -97,13 +100,19 @@ func (r *Root) end(callID uint64) {
 // canceled.
 type rootMethodCaller struct {
 	rpcreflect.MethodCaller
-
 	r *Root
+
+	methodName string
+	facadeName string
+	version    int
 }
 
 // Call implements rpcreflect.MethodCaller.Call.
 func (c rootMethodCaller) Call(ctx context.Context, objID string, arg reflect.Value) (reflect.Value, error) {
 	ctx, callID := c.r.start(ctx)
 	defer c.r.end(callID)
+	ctx = zapctx.WithFields(ctx, zap.String("facade", c.facadeName))
+	ctx = zapctx.WithFields(ctx, zap.String("method", c.methodName))
+	ctx = zapctx.WithFields(ctx, zap.Int("version", c.version))
 	return c.MethodCaller.Call(ctx, objID, arg)
 }
diff --git a/internal/jujuapi/websocket.go b/internal/jujuapi/websocket.go
@@ -100,8 +100,6 @@ func (s *apiServer) Kill() {
 
 // serveRoot serves an RPC root object on a websocket connection.
 func serveRoot(ctx context.Context, root root, logger jimm.DbAuditLogger, wsConn *websocket.Conn) {
-	ctx = zapctx.WithFields(ctx, zap.Bool("websocket", true))
-
 	// Note that although NewConn accepts a `RecorderFactory` input, the call to conn.ServeRoot
 	// also accepts a `RecorderFactory` and will override anything set during the call to NewConn.
 	conn := rpc.NewConn(