[MM-31359] remove duplicated error logs (#16583)

* remove duplicated error logs

* reflect review comments

* add context

* add error details

api4/job.go

@@ -10,7 +10,6 @@ import (
 	"time"
 
 	"github.com/mattermost/mattermost-server/v5/audit"
-	"github.com/mattermost/mattermost-server/v5/mlog"
 	"github.com/mattermost/mattermost-server/v5/model"
 )
 
@@ -65,7 +64,6 @@ func downloadJob(c *Context, w http.ResponseWriter, r *http.Request) {
 
 	job, err := c.App.GetJob(c.Params.JobId)
 	if err != nil {
-		mlog.Error(err.Error())
 		c.Err = err
 		return
 	}
@@ -80,7 +78,6 @@ func downloadJob(c *Context, w http.ResponseWriter, r *http.Request) {
 	filePath := filepath.Join(FILE_PATH, fileName)
 	fileReader, err := c.App.FileReader(filePath)
 	if err != nil {
-		mlog.Error(err.Error())
 		c.Err = err
 		c.Err.StatusCode = http.StatusNotFound
 		return
@@ -91,7 +88,6 @@ func downloadJob(c *Context, w http.ResponseWriter, r *http.Request) {
 	// already sets that for us
 	err = writeFileResponse(fileName, FILE_MIME, 0, time.Unix(0, job.LastActivityAt*int64(1000*1000)), *c.App.Config().ServiceSettings.WebserverMode, fileReader, true, w, r)
 	if err != nil {
-		mlog.Error(err.Error())
 		c.Err = err
 		return
 	}

api4/websocket.go

@@ -7,7 +7,6 @@ import (
 	"net/http"
 
 	"github.com/gorilla/websocket"
-	"github.com/mattermost/mattermost-server/v5/mlog"
 	"github.com/mattermost/mattermost-server/v5/model"
 )
 
@@ -25,7 +24,6 @@ func connectWebSocket(c *Context, w http.ResponseWriter, r *http.Request) {
 
 	ws, err := upgrader.Upgrade(w, r, nil)
 	if err != nil {
-		mlog.Error("websocket connect err.", mlog.Err(err))
 		c.Err = model.NewAppError("connect", "api.web_socket.connect.upgrade.app_error", nil, "", http.StatusInternalServerError)
 		return
 	}

app/app.go

@@ -371,7 +371,6 @@ func (a *App) notifyAdminsOfWarnMetricStatus(warnMetricId string, isE0Edition bo
 
 		channel, appErr := a.GetOrCreateDirectChannel(bot.UserId, sysAdmin.Id)
 		if appErr != nil {
-			mlog.Error("Cannot create channel for system bot notification!", mlog.String("Admin Id", sysAdmin.Id))
 			return appErr
 		}
 
@@ -484,7 +483,6 @@ func (a *App) NotifyAndSetWarnMetricAck(warnMetricId string, sender *model.User,
 			bodyPage.Props["Title"] = warnMetricDisplayTexts.EmailBody
 
 			if err := mailservice.SendMailUsingConfig(model.MM_SUPPORT_ADVISOR_ADDRESS, subject, bodyPage.Render(), a.Config(), false, sender.Email); err != nil {
-				mlog.Error("Error while sending email", mlog.String("destination email", model.MM_SUPPORT_ADVISOR_ADDRESS), mlog.Err(err))
 				return model.NewAppError("NotifyAndSetWarnMetricAck", "api.email.send_warn_metric_ack.failure.app_error", map[string]interface{}{"Error": err.Error()}, "", http.StatusInternalServerError)
 			}
 		}
@@ -526,7 +524,6 @@ func (a *App) setWarnMetricsStatusForId(warnMetricId string, status string) *mod
 		Name:  warnMetricId,
 		Value: status,
 	}); err != nil {
-		mlog.Error("Unable to write to database.", mlog.Err(err))
 		return model.NewAppError("setWarnMetricsStatusForId", "app.system.warn_metric.store.app_error", map[string]interface{}{"WarnMetricName": warnMetricId}, err.Error(), http.StatusInternalServerError)
 	}
 	return nil
@@ -544,7 +541,6 @@ func (a *App) RequestLicenseAndAckWarnMetric(warnMetricId string, isBot bool) *m
 
 	registeredUsersCount, err := a.Srv().Store.User().Count(model.UserCountOptions{})
 	if err != nil {
-		mlog.Error("Error retrieving the number of registered users", mlog.Err(err))
 		return model.NewAppError("RequestLicenseAndAckWarnMetric", "api.license.request_trial_license.fail_get_user_count.app_error", nil, err.Error(), http.StatusBadRequest)
 	}
 

app/auto_responder.go

@@ -4,7 +4,6 @@
 package app
 
 import (
-	"github.com/mattermost/mattermost-server/v5/mlog"
 	"github.com/mattermost/mattermost-server/v5/model"
 )
 
@@ -57,7 +56,6 @@ func (a *App) SendAutoResponse(channel *model.Channel, receiver *model.User, pos
 	}
 
 	if _, err := a.CreatePost(autoResponderPost, channel, false, false); err != nil {
-		mlog.Error(err.Error())
 		return false, err
 	}
 

app/bot.go

@@ -58,7 +58,6 @@ func (a *App) CreateBot(bot *model.Bot) (*model.Bot, *model.AppError) {
 	ownerUser, err := a.Srv().Store.User().Get(bot.OwnerId)
 	var nfErr *store.ErrNotFound
 	if err != nil && !errors.As(err, &nfErr) {
-		mlog.Error(err.Error())
 		return nil, model.NewAppError("CreateBot", "app.user.get.app_error", nil, err.Error(), http.StatusInternalServerError)
 	} else if ownerUser != nil {
 		// Send a message to the bot's creator to inform them that the bot needs to be added
@@ -88,14 +87,12 @@ func (a *App) getOrCreateWarnMetricsBot(botDef *model.Bot) (*model.Bot, *model.A
 	botUser, appErr := a.GetUserByUsername(botDef.Username)
 	if appErr != nil {
 		if appErr.StatusCode != http.StatusNotFound {
-			mlog.Error(appErr.Error())
 			return nil, appErr
 		}
 
 		// cannot find this bot user, save the user
 		user, nErr := a.Srv().Store.User().Save(model.UserFromBot(botDef))
 		if nErr != nil {
-			mlog.Error(nErr.Error())
 			var appError *model.AppError
 			var invErr *store.ErrInvalidInput
 			switch {

app/channel.go

@@ -108,7 +108,6 @@ func (a *App) JoinDefaultChannels(teamId string, user *model.User, shouldBeAdmin
 
 		_, nErr = a.Srv().Store.Channel().SaveMember(cm)
 		if histErr := a.Srv().Store.ChannelMemberHistory().LogJoinEvent(user.Id, channel.Id, model.GetMillis()); histErr != nil {
-			mlog.Error("Failed to update ChannelMemberHistory table", mlog.Err(histErr))
 			return model.NewAppError("JoinDefaultChannels", "app.channel_member_history.log_join_event.internal_error", nil, histErr.Error(), http.StatusInternalServerError)
 		}
 
@@ -298,7 +297,6 @@ func (a *App) CreateChannel(channel *model.Channel, addMember bool) (*model.Chan
 		}
 
 		if err := a.Srv().Store.ChannelMemberHistory().LogJoinEvent(channel.CreatorId, sc.Id, model.GetMillis()); err != nil {
-			mlog.Error("Failed to update ChannelMemberHistory table", mlog.Err(err))
 			return nil, model.NewAppError("CreateChannel", "app.channel_member_history.log_join_event.internal_error", nil, err.Error(), http.StatusInternalServerError)
 		}
 
@@ -417,12 +415,10 @@ func (a *App) createDirectChannel(userId string, otherUserId string) (*model.Cha
 	}
 
 	if err := a.Srv().Store.ChannelMemberHistory().LogJoinEvent(userId, channel.Id, model.GetMillis()); err != nil {
-		mlog.Error("Failed to update ChannelMemberHistory table", mlog.Err(err))
 		return nil, model.NewAppError("CreateDirectChannel", "app.channel_member_history.log_join_event.internal_error", nil, err.Error(), http.StatusInternalServerError)
 	}
 	if userId != otherUserId {
 		if err := a.Srv().Store.ChannelMemberHistory().LogJoinEvent(otherUserId, channel.Id, model.GetMillis()); err != nil {
-			mlog.Error("Failed to update ChannelMemberHistory table", mlog.Err(err))
 			return nil, model.NewAppError("CreateDirectChannel", "app.channel_member_history.log_join_event.internal_error", nil, err.Error(), http.StatusInternalServerError)
 		}
 	}
@@ -554,7 +550,6 @@ func (a *App) createGroupChannel(userIds []string, creatorId string) (*model.Cha
 			}
 		}
 		if err := a.Srv().Store.ChannelMemberHistory().LogJoinEvent(user.Id, channel.Id, model.GetMillis()); err != nil {
-			mlog.Error("Failed to update ChannelMemberHistory table", mlog.Err(err))
 			return nil, model.NewAppError("createGroupChannel", "app.channel_member_history.log_join_event.internal_error", nil, err.Error(), http.StatusInternalServerError)
 		}
 	}
@@ -1330,13 +1325,11 @@ func (a *App) addUserToChannel(user *model.User, channel *model.Channel, teamMem
 
 	newMember, nErr = a.Srv().Store.Channel().SaveMember(newMember)
 	if nErr != nil {
-		mlog.Error("Failed to add member", mlog.String("user_id", user.Id), mlog.String("channel_id", channel.Id), mlog.Err(nErr))
-		return nil, model.NewAppError("AddUserToChannel", "api.channel.add_user.to.channel.failed.app_error", nil, "", http.StatusInternalServerError)
+		return nil, model.NewAppError("AddUserToChannel", "api.channel.add_user.to.channel.failed.app_error", nil, fmt.Sprintf("failed to add member: user_id: %s, channel_id:%s", user.Id, channel.Id), http.StatusInternalServerError)
 	}
 	a.WaitForChannelMembership(channel.Id, user.Id)
 
 	if nErr := a.Srv().Store.ChannelMemberHistory().LogJoinEvent(user.Id, channel.Id, model.GetMillis()); nErr != nil {
-		mlog.Error("Failed to update ChannelMemberHistory table", mlog.Err(nErr))
 		return nil, model.NewAppError("AddUserToChannel", "app.channel_member_history.log_join_event.internal_error", nil, nErr.Error(), http.StatusInternalServerError)
 	}
 

app/command.go

@@ -530,7 +530,7 @@ func (a *App) HandleCommandResponse(command *model.Command, args *model.CommandA
 	_, err := a.HandleCommandResponsePost(command, args, response, builtIn)
 
 	if err != nil {
-		mlog.Error("error occurred in handling command response post", mlog.Err(err))
+		mlog.Debug("Error occurred in handling command response post", mlog.Err(err))
 		lastError = err
 	}
 
@@ -539,7 +539,7 @@ func (a *App) HandleCommandResponse(command *model.Command, args *model.CommandA
 			_, err := a.HandleCommandResponsePost(command, args, resp, builtIn)
 
 			if err != nil {
-				mlog.Error("error occurred in handling command response post", mlog.Err(err))
+				mlog.Debug("Error occurred in handling command response post", mlog.Err(err))
 				lastError = err
 			}
 		}

app/ldap.go

@@ -52,8 +52,7 @@ func (a *App) GetLdapGroup(ldapGroupID string) (*model.Group, *model.AppError) {
 			return nil, err
 		}
 	} else {
-		ae := model.NewAppError("GetLdapGroup", "ent.ldap.app_error", nil, "", http.StatusNotImplemented)
-		mlog.Error("Unable to use ldap", mlog.String("ldap_group_id", ldapGroupID), mlog.Err(ae))
+		ae := model.NewAppError("GetLdapGroup", "ent.ldap.app_error", map[string]interface{}{"ldap_group_id": ldapGroupID}, "", http.StatusNotImplemented)
 		return nil, ae
 	}
 
@@ -74,7 +73,6 @@ func (a *App) GetAllLdapGroupsPage(page int, perPage int, opts model.LdapGroupSe
 		}
 	} else {
 		ae := model.NewAppError("GetAllLdapGroupsPage", "ent.ldap.app_error", nil, "", http.StatusNotImplemented)
-		mlog.Error("Unable to use ldap", mlog.Err(ae))
 		return nil, 0, ae
 	}
 

app/login.go

@@ -69,7 +69,7 @@ func (a *App) AuthenticateUserForLogin(id, loginId, password, mfaToken, cwsToken
 		}
 		token, err := a.Srv().Store.Token().GetByToken(cwsToken)
 		if nfErr := new(store.ErrNotFound); err != nil && !errors.As(err, &nfErr) {
-			mlog.Error("error retrieving the cws token from the store", mlog.Err(err))
+			mlog.Debug("Error retrieving the cws token from the store", mlog.Err(err))
 			return nil, model.NewAppError("AuthenticateUserForLogin",
 				"api.user.login_by_cws.invalid_token.app_error", nil, "", http.StatusInternalServerError)
 		}
@@ -87,7 +87,7 @@ func (a *App) AuthenticateUserForLogin(id, loginId, password, mfaToken, cwsToken
 			}
 			err := a.Srv().Store.Token().Save(token)
 			if err != nil {
-				mlog.Error("error storing the cws token in the store", mlog.Err(err))
+				mlog.Debug("Error storing the cws token in the store", mlog.Err(err))
 				return nil, model.NewAppError("AuthenticateUserForLogin",
 					"api.user.login_by_cws.invalid_token.app_error", nil, "", http.StatusInternalServerError)
 			}

app/notification.go

@@ -422,8 +422,7 @@ func (a *App) SendNotifications(post *model.Post, team *model.Team, channel *mod
 	if *a.Config().ServiceSettings.CollapsedThreads != model.COLLAPSED_THREADS_DISABLED && post.RootId != "" {
 		thread, err := a.Srv().Store.Thread().Get(post.RootId)
 		if err != nil {
-			mlog.Error("Cannot get thread", mlog.String("id", post.RootId))
-			return nil, err
+			return nil, errors.Wrapf(err, "cannot get thread %q", post.RootId)
 		}
 		payload := thread.ToJson()
 		for _, uid := range thread.Participants {

app/oauth.go

@@ -247,7 +247,6 @@ func (a *App) GetOAuthAccessTokenForImplicitFlow(userId string, authRequest *mod
 	accessData := &model.AccessData{ClientId: authRequest.ClientId, UserId: user.Id, Token: session.Token, RefreshToken: "", RedirectUri: authRequest.RedirectUri, ExpiresAt: session.ExpiresAt, Scope: authRequest.Scope}
 
 	if _, err := a.Srv().Store.OAuth().SaveAccessData(accessData); err != nil {
-		mlog.Error("error saving oauth access data in implicit flow", mlog.Err(err))
 		return nil, model.NewAppError("GetOAuthAccessToken", "api.oauth.get_access_token.internal_saving.app_error", nil, "", http.StatusInternalServerError)
 	}
 
@@ -327,7 +326,6 @@ func (a *App) GetOAuthAccessTokenForCodeFlow(clientId, grantType, redirectUri, c
 			accessData = &model.AccessData{ClientId: clientId, UserId: user.Id, Token: session.Token, RefreshToken: model.NewId(), RedirectUri: redirectUri, ExpiresAt: session.ExpiresAt, Scope: authData.Scope}
 
 			if _, nErr = a.Srv().Store.OAuth().SaveAccessData(accessData); nErr != nil {
-				mlog.Error("error saving oauth access data in token for code flow", mlog.Err(nErr))
 				return nil, model.NewAppError("GetOAuthAccessToken", "api.oauth.get_access_token.internal_saving.app_error", nil, "", http.StatusInternalServerError)
 			}
 
@@ -399,7 +397,6 @@ func (a *App) newSessionUpdateToken(appName string, accessData *model.AccessData
 	accessData.ExpiresAt = session.ExpiresAt
 
 	if _, err := a.Srv().Store.OAuth().UpdateAccessData(accessData); err != nil {
-		mlog.Error("error updating oauth access data", mlog.Err(err))
 		return nil, model.NewAppError("newSessionUpdateToken", "web.get_access_token.internal_saving.app_error", nil, "", http.StatusInternalServerError)
 	}
 	accessRsp := &model.AccessResponse{

app/upload.go

@@ -87,7 +87,6 @@ func (a *App) runPluginsHook(info *model.FileInfo, file io.Reader) *model.AppErr
 	if written > 0 {
 		info.Size = written
 		if fileErr := a.MoveFile(tmpPath, info.Path); fileErr != nil {
-			mlog.Error("Failed to move file", mlog.Err(fileErr))
 			return model.NewAppError("runPluginsHook", "app.upload.run_plugins_hook.move_fail",
 				nil, fileErr.Error(), http.StatusInternalServerError)
 		}

app/user.go

@@ -213,7 +213,7 @@ func (s *Server) IsFirstUserAccount() bool {
 	if cachedSessions == 0 {
 		count, err := s.Store.User().Count(model.UserCountOptions{IncludeDeleted: true})
 		if err != nil {
-			mlog.Error("There was a error fetching if first user account", mlog.Err(err))
+			mlog.Debug("There was an error fetching if first user account", mlog.Err(err))
 			return false
 		}
 		if count <= 0 {
@@ -299,7 +299,6 @@ func (a *App) createUser(user *model.User) (*model.User, *model.AppError) {
 
 	ruser, nErr := a.Srv().Store.User().Save(user)
 	if nErr != nil {
-		mlog.Error("Couldn't save the user", mlog.Err(nErr))
 		var appErr *model.AppError
 		var invErr *store.ErrInvalidInput
 		switch {

model/session.go

@@ -162,7 +162,7 @@ func (s *Session) IsMobile() bool {
 	}
 	isMobile, err := strconv.ParseBool(val)
 	if err != nil {
-		mlog.Error("Error parsing boolean property from Session", mlog.Err(err))
+		mlog.Debug("Error parsing boolean property from Session", mlog.Err(err))
 		return false
 	}
 	return isMobile
@@ -175,7 +175,7 @@ func (s *Session) IsSaml() bool {
 	}
 	isSaml, err := strconv.ParseBool(val)
 	if err != nil {
-		mlog.Error("Error parsing boolean property from Session", mlog.Err(err))
+		mlog.Debug("Error parsing boolean property from Session", mlog.Err(err))
 		return false
 	}
 	return isSaml
@@ -188,7 +188,7 @@ func (s *Session) IsOAuthUser() bool {
 	}
 	isOAuthUser, err := strconv.ParseBool(val)
 	if err != nil {
-		mlog.Error("Error parsing boolean property from Session", mlog.Err(err))
+		mlog.Debug("Error parsing boolean property from Session", mlog.Err(err))
 		return false
 	}
 	return isOAuthUser

services/awsmeter/awsmeter.go

@@ -53,7 +53,7 @@ func New(store store.Store, config *model.Config) *AwsMeter {
 
 	service, err := newAWSMarketplaceMeteringService()
 	if err != nil {
-		mlog.Error("newAWSMeterService", mlog.String("error", err.Error()))
+		mlog.Debug("Could not create AWS metering service", mlog.String("error", err.Error()))
 		return nil
 	}
 

services/mailservice/mail.go

@@ -184,7 +184,6 @@ func NewSMTPClientAdvanced(ctx context.Context, conn net.Conn, hostname string,
 	if hostname != "" {
 		err := c.Hello(hostname)
 		if err != nil {
-			mlog.Error("Failed to to set the HELO to SMTP server", mlog.Err(err))
 			return nil, model.NewAppError("SendMail", "utils.mail.connect_smtp.helo.app_error", nil, err.Error(), http.StatusInternalServerError)
 		}
 	}

store/searchlayer/post_layer.go

@@ -8,6 +8,7 @@ import (
 	"github.com/mattermost/mattermost-server/v5/model"
 	"github.com/mattermost/mattermost-server/v5/services/searchengine"
 	"github.com/mattermost/mattermost-server/v5/store"
+	"github.com/pkg/errors"
 )
 
 type SearchPostStore struct {
@@ -136,8 +137,7 @@ func (s SearchPostStore) searchPostsInTeamForUserByEngine(engine searchengine.Se
 	// We only allow the user to search in channels they are a member of.
 	userChannels, err2 := s.rootStore.Channel().GetChannels(teamId, userId, paramsList[0].IncludeDeletedChannels, 0)
 	if err2 != nil {
-		mlog.Error("error getting channel for user", mlog.Err(err2))
-		return nil, err2
+		return nil, errors.Wrap(err2, "error getting channel for user")
 	}
 
 	postIds, matches, err := engine.SearchPosts(userChannels, paramsList, page, perPage)

utils/html.go

@@ -112,7 +112,7 @@ func (t *HTMLTemplate) RenderToWriter(w io.Writer) error {
 	}
 
 	if err := t.Templates.ExecuteTemplate(w, t.TemplateName, t); err != nil {
-		mlog.Error("Error rendering template", mlog.String("template_name", t.TemplateName), mlog.Err(err))
+		mlog.Warn("Error rendering template", mlog.String("template_name", t.TemplateName), mlog.Err(err))
 		return err
 	}
 

wsapi/status.go

@@ -21,7 +21,7 @@ func (api *API) getStatuses(req *model.WebSocketRequest) (map[string]interface{}
 func (api *API) getStatusesByIds(req *model.WebSocketRequest) (map[string]interface{}, *model.AppError) {
 	var userIds []string
 	if userIds = model.ArrayFromInterface(req.Data["user_ids"]); len(userIds) == 0 {
-		mlog.Error(model.StringInterfaceToJson(req.Data))
+		mlog.Debug("Error while parsing user_ids", mlog.String("data", model.StringInterfaceToJson(req.Data)))
 		return nil, NewInvalidWebSocketParamError(req.Action, "user_ids")
 	}