Improve logging and refactor isEmailActive

Signed-off-by: Andrew Thornton <[email protected]>

Author: zeripath

models/user_mail.go

@@ -74,14 +74,15 @@ func GetEmailAddressByID(uid, id int64) (*EmailAddress, error) {
 	return email, nil
 }
 
-func isEmailActive(e Engine, email string, userID, emailID int64) (bool, error) {
+// isEmailActive check if email is activated with a different emailID
+func isEmailActive(e Engine, email string, excludeEmailID int64) (bool, error) {
 	if len(email) == 0 {
 		return true, nil
 	}
 
 	// Can't filter by boolean field unless it's explicit
 	cond := builder.NewCond()
-	cond = cond.And(builder.Eq{"lower_email": strings.ToLower(email)}, builder.Neq{"id": emailID})
+	cond = cond.And(builder.Eq{"lower_email": strings.ToLower(email)}, builder.Neq{"id": excludeEmailID})
 	if setting.Service.RegisterEmailConfirm {
 		// Inactive (unvalidated) addresses don't count as active if email validation is required
 		cond = cond.And(builder.Eq{"is_activated": true})
@@ -90,7 +91,7 @@ func isEmailActive(e Engine, email string, userID, emailID int64) (bool, error)
 	var em EmailAddress
 	if has, err := e.Where(cond).Get(&em); has || err != nil {
 		if has {
-			log.Info("isEmailActive('%s',%d,%d) found duplicate in email ID %d", email, userID, emailID, em.ID)
+			log.Info("isEmailActive(%q, %d) found duplicate in email ID %d", email, excludeEmailID, em.ID)
 		}
 		return has, err
 	}
@@ -387,14 +388,14 @@ func ActivateUserEmail(userID int64, email string, activate bool) (err error) {
 		return nil
 	}
 	if activate {
-		if used, err := isEmailActive(sess, email, 0, addr.ID); err != nil {
-			return fmt.Errorf("isEmailActive(): %v", err)
+		if used, err := isEmailActive(sess, email, addr.ID); err != nil {
+			return fmt.Errorf("unable to check isEmailActive() for %s: %v", email, err)
 		} else if used {
 			return ErrEmailAlreadyUsed{Email: email}
 		}
 	}
 	if err = addr.updateActivation(sess, activate); err != nil {
-		return fmt.Errorf("updateActivation(): %v", err)
+		return fmt.Errorf("unable to updateActivation() for %d:%s: %w", addr.ID, addr.Email, err)
 	}
 
 	// Activate/deactivate a user's primary email address and account
@@ -403,16 +404,16 @@ func ActivateUserEmail(userID int64, email string, activate bool) (err error) {
 		if has, err := sess.Get(&user); err != nil {
 			return err
 		} else if !has {
-			return fmt.Errorf("no such user: %d (%s)", userID, email)
+			return fmt.Errorf("no user with ID: %d and Email: %s", userID, email)
 		}
-		// The user's activation state should synchronized with the primary email
+		// The user's activation state should be synchronized with the primary email
 		if user.IsActive != activate {
 			user.IsActive = activate
 			if user.Rands, err = GetUserSalt(); err != nil {
-				return fmt.Errorf("generate salt: %v", err)
+				return fmt.Errorf("unable to generate salt: %v", err)
 			}
 			if err = updateUserCols(sess, &user, "is_active", "rands"); err != nil {
-				return fmt.Errorf("updateUserCols(): %v", err)
+				return fmt.Errorf("unable to updateUserCols() for user ID: %d: %v", userID, err)
 			}
 		}
 	}

routers/web/user/auth.go

@@ -1430,19 +1430,21 @@ func handleAccountActivation(ctx *context.Context, user *models.User) {
 	}
 
 	if err := models.ActivateUserEmail(user.ID, user.Email, true); err != nil {
-		log.Error(fmt.Sprintf("Error active user mail: %v", err))
+		log.Error("Unable to activate email for user: %-v with email: %s: %v", user, user.Email, err)
+		ctx.ServerError("ActivateUserEmail", err)
+		return
 	}
 
 	log.Trace("User activated: %s", user.Name)
 
 	if err := ctx.Session.Set("uid", user.ID); err != nil {
-		log.Error(fmt.Sprintf("Error setting uid in session: %v", err))
+		log.Error("Error setting uid in session[%s]: %v", ctx.Session.ID(), err)
 	}
 	if err := ctx.Session.Set("uname", user.Name); err != nil {
-		log.Error(fmt.Sprintf("Error setting uname in session: %v", err))
+		log.Error("Error setting uname in session[%s]: %v", ctx.Session.ID(), err)
 	}
 	if err := ctx.Session.Release(); err != nil {
-		log.Error("Error storing session: %v", err)
+		log.Error("Error storing session[%s]: %v", ctx.Session.ID(), err)
 	}
 
 	ctx.Flash.Success(ctx.Tr("auth.account_activated"))

routers/web/user/setting/account.go

@@ -116,18 +116,18 @@ func EmailPost(ctx *context.Context) {
 			return
 		}
 		if email == nil {
-			log.Error("Send activation: EmailAddress not found; user:%d, id: %d", ctx.User.ID, id)
+			log.Warn("Send activation failed: EmailAddress[%d] not found for user: %-v", id, ctx.User)
 			ctx.Redirect(setting.AppSubURL + "/user/settings/account")
 			return
 		}
 		if email.IsActivated {
-			log.Error("Send activation: email not set for activation")
+			log.Debug("Send activation failed: email %s is already activated for user: %-v", email.Email, ctx.User)
 			ctx.Redirect(setting.AppSubURL + "/user/settings/account")
 			return
 		}
 		if email.IsPrimary {
 			if ctx.User.IsActive && !setting.Service.RegisterEmailConfirm {
-				log.Error("Send activation: email not set for activation")
+				log.Debug("Send activation failed: email %s is already activated for user: %-v", email.Email, ctx.User)
 				ctx.Redirect(setting.AppSubURL + "/user/settings/account")
 				return
 			}