From 0726f1b143fa2ea5e471e9166c6f50133822fedb Mon Sep 17 00:00:00 2001 From: Ralf Haferkamp Date: Wed, 24 May 2023 15:57:38 +0200 Subject: [PATCH 1/3] graph/users: Sanitize some log levels The "calling function XYZ" log messages should only appear at debug level. Message indicating client errors when creating a user (e.g. invalid characters in username or missing attributes) are logged at info level (instead of debug) now. --- services/graph/pkg/service/v0/users.go | 34 +++++++++++++------------- 1 file changed, 17 insertions(+), 17 deletions(-) diff --git a/services/graph/pkg/service/v0/users.go b/services/graph/pkg/service/v0/users.go index 5846247cf..b77444caa 100644 --- a/services/graph/pkg/service/v0/users.go +++ b/services/graph/pkg/service/v0/users.go @@ -31,7 +31,7 @@ import ( // GetMe implements the Service interface. func (g Graph) GetMe(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Msg("calling get user in /me") + logger.Debug().Msg("calling get user in /me") sanitizedPath := strings.TrimPrefix(r.URL.Path, "/graph/v1.0/") odataReq, err := godata.ParseRequest(r.Context(), sanitizedPath, r.URL.Query()) @@ -116,7 +116,7 @@ func (g Graph) fetchAppRoleAssignments(ctx context.Context, accountuuid string) // GetUserDrive implements the Service interface. func (g Graph) GetUserDrive(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Interface("query", r.URL.Query()).Msg("calling get user drive") + logger.Debug().Interface("query", r.URL.Query()).Msg("calling get user drive") userID, err := url.PathUnescape(chi.URLParam(r, "userID")) if err != nil { @@ -191,7 +191,7 @@ func (g Graph) GetUserDrive(w http.ResponseWriter, r *http.Request) { // GetUsers implements the Service interface. func (g Graph) GetUsers(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Interface("query", r.URL.Query()).Msg("calling get users") + logger.Debug().Interface("query", r.URL.Query()).Msg("calling get users") sanitizedPath := strings.TrimPrefix(r.URL.Path, "/graph/v1.0/") odataReq, err := godata.ParseRequest(r.Context(), sanitizedPath, r.URL.Query()) if err != nil { @@ -262,36 +262,36 @@ func (g Graph) GetUsers(w http.ResponseWriter, r *http.Request) { // PostUser implements the Service interface. func (g Graph) PostUser(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Interface("body", r.Body).Msg("calling create user") + logger.Debug().Msg("calling create user") u := libregraph.NewUser() err := StrictJSONUnmarshal(r.Body, u) if err != nil { - logger.Debug().Err(err).Interface("body", r.Body).Msg("could not create user: invalid request body") + logger.Info().Err(err).Msg("could not create user: invalid request body") errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, fmt.Sprintf("invalid request body: %v", err.Error())) return } if _, ok := u.GetDisplayNameOk(); !ok { - logger.Debug().Err(err).Interface("user", u).Msg("could not create user: missing required Attribute: 'displayName'") + logger.Info().Err(err).Interface("user", u).Msg("could not create user: missing required Attribute: 'displayName'") errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, "missing required Attribute: 'displayName'") return } if accountName, ok := u.GetOnPremisesSamAccountNameOk(); ok { if !g.isValidUsername(*accountName) { - logger.Debug().Str("username", *accountName).Msg("could not create user: username must be at least the local part of an email") - errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, fmt.Sprintf("username %s must be at least the local part of an email", *u.OnPremisesSamAccountName)) + logger.Info().Str("username", *accountName).Msg("could not create user: invalid username") + errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, "Invalid username") return } } else { - logger.Debug().Interface("user", u).Msg("could not create user: missing required Attribute: 'onPremisesSamAccountName'") + logger.Info().Interface("user", u).Msg("could not create user: missing required Attribute: 'onPremisesSamAccountName'") errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, "missing required Attribute: 'onPremisesSamAccountName'") return } if mail, ok := u.GetMailOk(); ok { if !isValidEmail(*mail) { - logger.Debug().Str("mail", *u.Mail).Msg("could not create user: invalid email address") - errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, fmt.Sprintf("%v is not a valid email address", *u.Mail)) + logger.Info().Str("mail", *u.Mail).Msg("could not create user: invalid email address") + errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, "invalid email address") return } } @@ -300,14 +300,14 @@ func (g Graph) PostUser(w http.ResponseWriter, r *http.Request) { // generating them in the backend ourselves or rely on the Backend's // storage (e.g. LDAP) to provide a unique ID. if _, ok := u.GetIdOk(); ok { - logger.Debug().Interface("user", u).Msg("could not create user: user id is a read-only attribute") + logger.Info().Interface("user", u).Msg("could not create user: user id is a read-only attribute") errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, "user id is a read-only attribute") return } if u.HasUserType() { if !isValidUserType(*u.UserType) { - logger.Debug().Interface("user", u).Msg("invalid userType attribute") + logger.Info().Interface("user", u).Msg("invalid userType attribute") errorcode.InvalidRequest.Render(w, r, http.StatusBadRequest, "invalid userType attribute, valid options are 'Member' or 'Guest'") return } @@ -317,7 +317,7 @@ func (g Graph) PostUser(w http.ResponseWriter, r *http.Request) { logger.Debug().Interface("user", u).Msg("calling create user on backend") if u, err = g.identityBackend.CreateUser(r.Context(), *u); err != nil { - logger.Debug().Err(err).Msg("could not create user: backend error") + logger.Error().Err(err).Msg("could not create user: backend error") var ecErr errorcode.Error if errors.As(err, &ecErr) { ecErr.Render(w, r) @@ -355,7 +355,7 @@ func (g Graph) PostUser(w http.ResponseWriter, r *http.Request) { // GetUser implements the Service interface. func (g Graph) GetUser(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Msg("calling get user") + logger.Debug().Msg("calling get user") sanitizedPath := strings.TrimPrefix(r.URL.Path, "/graph/v1.0/") @@ -499,7 +499,7 @@ func (g Graph) GetUser(w http.ResponseWriter, r *http.Request) { // DeleteUser implements the Service interface. func (g Graph) DeleteUser(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Msg("calling delete user") + logger.Debug().Msg("calling delete user") sanitizedPath := strings.TrimPrefix(r.URL.Path, "/graph/v1.0/") userID := chi.URLParam(r, "userID") userID, err := url.PathUnescape(userID) @@ -624,7 +624,7 @@ func (g Graph) DeleteUser(w http.ResponseWriter, r *http.Request) { // ExistingUser func (g Graph) PatchUser(w http.ResponseWriter, r *http.Request) { logger := g.logger.SubloggerWithRequestID(r.Context()) - logger.Info().Msg("calling patch user") + logger.Debug().Msg("calling patch user") nameOrID := chi.URLParam(r, "userID") nameOrID, err := url.PathUnescape(nameOrID) if err != nil { From efc5e249e293f13f06298510778146425d471220 Mon Sep 17 00:00:00 2001 From: Ralf Haferkamp Date: Wed, 24 May 2023 16:19:50 +0200 Subject: [PATCH 2/3] graph: Clarify wording for GRAPH_USERNAME_MATCH setting --- services/graph/pkg/config/config.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/graph/pkg/config/config.go b/services/graph/pkg/config/config.go index 0fe2745d4..3dfcf2522 100644 --- a/services/graph/pkg/config/config.go +++ b/services/graph/pkg/config/config.go @@ -104,7 +104,7 @@ type Identity struct { // API represents API configuration parameters. type API struct { GroupMembersPatchLimit int `yaml:"group_members_patch_limit" env:"GRAPH_GROUP_MEMBERS_PATCH_LIMIT" desc:"The amount of group members allowed to be added with a single patch request."` - UsernameMatch string `yaml:"graph_username_match" env:"GRAPH_USERNAME_MATCH" desc:"Option to allow legacy usernames. Supported options are 'default' and 'none'."` + UsernameMatch string `yaml:"graph_username_match" env:"GRAPH_USERNAME_MATCH" desc:"Apply restrictions to usernames. Supported values are 'default' and 'none'. When set to 'default', user names must not start with a number and are restricted to ASCII characters. When set to 'none', no restrictions are applied. The default value is 'default'."` AssignDefaultUserRole bool `yaml:"graph_assign_default_user_role" env:"GRAPH_ASSIGN_DEFAULT_USER_ROLE" desc:"Whether to assign newly created users the default role 'User'. Set this to 'false' if you want to assign roles manually, or if the role assignment should happen at first login. Set this to 'true' (the default) to assign the role 'User' when creating a new user."` } From 3dc0fff1f449c991de7e39d27f869783435f2334 Mon Sep 17 00:00:00 2001 From: Ralf Haferkamp Date: Wed, 24 May 2023 16:21:12 +0200 Subject: [PATCH 3/3] proxy: Return an error when autoprovision a user fails Fixes: #6194 --- services/proxy/pkg/middleware/account_resolver.go | 4 ++++ services/proxy/pkg/user/backend/cs3.go | 2 ++ 2 files changed, 6 insertions(+) diff --git a/services/proxy/pkg/middleware/account_resolver.go b/services/proxy/pkg/middleware/account_resolver.go index c8c16c9c7..3847f02e7 100644 --- a/services/proxy/pkg/middleware/account_resolver.go +++ b/services/proxy/pkg/middleware/account_resolver.go @@ -78,10 +78,14 @@ func (m accountResolver) ServeHTTP(w http.ResponseWriter, req *http.Request) { user, err = m.userProvider.CreateUserFromClaims(req.Context(), claims) if err != nil { m.logger.Error().Err(err).Msg("Autoprovisioning user failed") + w.WriteHeader(http.StatusInternalServerError) + return } user, token, err = m.userProvider.GetUserByClaims(req.Context(), "userid", user.Id.OpaqueId) if err != nil { m.logger.Error().Err(err).Str("userid", user.Id.OpaqueId).Msg("Error getting token for autoprovisioned user") + w.WriteHeader(http.StatusUnauthorized) + return } } diff --git a/services/proxy/pkg/user/backend/cs3.go b/services/proxy/pkg/user/backend/cs3.go index 59ef8dbaf..0dcbc8fd1 100644 --- a/services/proxy/pkg/user/backend/cs3.go +++ b/services/proxy/pkg/user/backend/cs3.go @@ -229,6 +229,8 @@ func (c cs3backend) isAlreadyExists(resp *http.Response) (bool, error) { return false, err } + c.logger.Warn().Str("OData Error", oDataErr.Error.Message).Msg("Error Response") + if oDataErr.Error.Code == errorcode.NameAlreadyExists.String() { return true, nil }