From 83d31ec907a55c2662e4b0ac2094a29b5ee7c00f Mon Sep 17 00:00:00 2001 From: Ibrahim Serdar Acikgoz Date: Fri, 15 Jan 2021 09:58:34 +0300 Subject: [PATCH] [MM-31573] update log levels for the app package (#16629) * update log levels for the app package * reflect review comments Co-authored-by: Mattermod --- app/app.go | 4 ++-- app/bot.go | 5 ++-- app/channel.go | 30 +++++++++++++----------- app/cluster_discovery.go | 14 +++++------- app/command.go | 2 +- app/config.go | 4 ++-- app/emoji.go | 2 +- app/file.go | 2 +- app/import_functions.go | 8 ++++--- app/integration_action.go | 2 +- app/ldap.go | 4 ++-- app/license.go | 2 +- app/notification.go | 2 +- app/notification_email.go | 18 ++++++++------- app/notification_email_test.go | 9 +++++--- app/notification_push.go | 2 +- app/oauth.go | 10 ++++---- app/plugin.go | 4 ++-- app/plugin_install.go | 12 +++++----- app/plugin_key_value_store.go | 6 ++--- app/plugin_signature.go | 2 +- app/post.go | 21 +++++++++-------- app/product_notices.go | 4 ++-- app/ratelimit.go | 11 ++++----- app/server.go | 24 +++++++++---------- app/server_test.go | 4 +--- app/session.go | 15 +++++------- app/status.go | 4 ++-- app/team.go | 14 ++++++------ app/upload.go | 10 ++++---- app/user.go | 42 +++++++++++++++++----------------- app/web_conn.go | 16 ++++++++++--- app/websocket_router.go | 6 ++++- 33 files changed, 164 insertions(+), 151 deletions(-) diff --git a/app/app.go b/app/app.go index 1a2f9bbc8d..b38ff1588d 100644 --- a/app/app.go +++ b/app/app.go @@ -315,7 +315,7 @@ func (a *App) getWarnMetricStatusAndDisplayTextsForId(warnMetricId string, T i18 warnMetricDisplayTexts.BotMessageBody = T("api.server.warn_metric.number_of_posts_2M.notification_body") } default: - mlog.Error("Invalid metric id", mlog.String("id", warnMetricId)) + mlog.Debug("Invalid metric id", mlog.String("id", warnMetricId)) return nil, nil } @@ -464,7 +464,7 @@ func (a *App) NotifyAndSetWarnMetricAck(warnMetricId string, sender *model.User, //same definition as the active users count metric displayed in the SystemConsole Analytics section registeredUsersCount, cerr := a.Srv().Store.User().Count(model.UserCountOptions{}) if cerr != nil { - mlog.Error("Error retrieving the number of registered users", mlog.Err(cerr)) + mlog.Warn("Error retrieving the number of registered users", mlog.Err(cerr)) } else { bodyPage.Props["RegisteredUsersHeader"] = T("api.templates.warn_metric_ack.body.registered_users_header") bodyPage.Props["RegisteredUsersValue"] = registeredUsersCount diff --git a/app/bot.go b/app/bot.go index ecd4b16cc6..6591c73533 100644 --- a/app/bot.go +++ b/app/bot.go @@ -137,7 +137,6 @@ func (a *App) getOrCreateWarnMetricsBot(botDef *model.Bot) (*model.Bot, *model.A //return the bot for this user savedBot, appErr := a.GetBot(botUser.Id, false) if appErr != nil { - mlog.Error(appErr.Error()) return nil, appErr } @@ -354,7 +353,7 @@ func (a *App) disableUserBots(userId string) *model.AppError { for _, bot := range userBots { _, err := a.UpdateBotActive(bot.UserId, false) if err != nil { - mlog.Error("Unable to deactivate bot.", mlog.String("bot_user_id", bot.UserId), mlog.Err(err)) + mlog.Warn("Unable to deactivate bot.", mlog.String("bot_user_id", bot.UserId), mlog.Err(err)) } } @@ -555,7 +554,7 @@ func (a *App) DeleteBotIconImage(botUserId string) *model.AppError { } if nErr := a.Srv().Store.User().UpdateLastPictureUpdate(botUserId); nErr != nil { - mlog.Error(nErr.Error()) + mlog.Warn(nErr.Error()) } bot.LastIconUpdate = int64(0) diff --git a/app/channel.go b/app/channel.go index e47be7513e..c011dcaf07 100644 --- a/app/channel.go +++ b/app/channel.go @@ -112,7 +112,9 @@ func (a *App) JoinDefaultChannels(teamId string, user *model.User, shouldBeAdmin } if *a.Config().ServiceSettings.ExperimentalEnableDefaultChannelLeaveJoinMessages { - a.postJoinMessageForDefaultChannel(user, requestor, channel) + if aErr := a.postJoinMessageForDefaultChannel(user, requestor, channel); aErr != nil { + mlog.Warn("Failed to post join/leave message", mlog.Err(aErr)) + } } a.invalidateCacheForChannelMembers(channel.Id) @@ -142,28 +144,30 @@ func (a *App) JoinDefaultChannels(teamId string, user *model.User, shouldBeAdmin return nil } -func (a *App) postJoinMessageForDefaultChannel(user *model.User, requestor *model.User, channel *model.Channel) { +func (a *App) postJoinMessageForDefaultChannel(user *model.User, requestor *model.User, channel *model.Channel) *model.AppError { if channel.Name == model.DEFAULT_CHANNEL { if requestor == nil { if err := a.postJoinTeamMessage(user, channel); err != nil { - mlog.Error("Failed to post join/leave message", mlog.Err(err)) + return err } } else { if err := a.postAddToTeamMessage(requestor, user, channel, ""); err != nil { - mlog.Error("Failed to post join/leave message", mlog.Err(err)) + return err } } } else { if requestor == nil { if err := a.postJoinChannelMessage(user, channel); err != nil { - mlog.Error("Failed to post join/leave message", mlog.Err(err)) + return err } } else { if err := a.PostAddToChannelMessage(requestor, user, channel, ""); err != nil { - mlog.Error("Failed to post join/leave message", mlog.Err(err)) + return err } } } + + return nil } func (a *App) CreateChannelWithUser(channel *model.Channel, userId string) (*model.Channel, *model.AppError) { @@ -733,7 +737,7 @@ func (a *App) RestoreChannel(channel *model.Channel, userId string) (*model.Chan } if _, err := a.CreatePost(post, channel, false, true); err != nil { - mlog.Error("Failed to post unarchive message", mlog.Err(err)) + mlog.Warn("Failed to post unarchive message", mlog.Err(err)) } } @@ -753,19 +757,19 @@ func (a *App) PatchChannel(channel *model.Channel, patch *model.ChannelPatch, us if oldChannelDisplayName != channel.DisplayName { if err = a.PostUpdateChannelDisplayNameMessage(userId, channel, oldChannelDisplayName, channel.DisplayName); err != nil { - mlog.Error(err.Error()) + mlog.Warn(err.Error()) } } if channel.Header != oldChannelHeader { if err = a.PostUpdateChannelHeaderMessage(userId, channel, oldChannelHeader, channel.Header); err != nil { - mlog.Error(err.Error()) + mlog.Warn(err.Error()) } } if channel.Purpose != oldChannelPurpose { if err = a.PostUpdateChannelPurposeMessage(userId, channel, oldChannelPurpose, channel.Purpose); err != nil { - mlog.Error(err.Error()) + mlog.Warn(err.Error()) } } @@ -1248,21 +1252,21 @@ func (a *App) DeleteChannel(channel *model.Channel, userId string) *model.AppErr } if _, err := a.CreatePost(post, channel, false, true); err != nil { - mlog.Error("Failed to post archive message", mlog.Err(err)) + mlog.Warn("Failed to post archive message", mlog.Err(err)) } } now := model.GetMillis() for _, hook := range incomingHooks { if err := a.Srv().Store.Webhook().DeleteIncoming(hook.Id, now); err != nil { - mlog.Error("Encountered error deleting incoming webhook", mlog.String("hook_id", hook.Id), mlog.Err(err)) + mlog.Warn("Encountered error deleting incoming webhook", mlog.String("hook_id", hook.Id), mlog.Err(err)) } a.invalidateCacheForWebhook(hook.Id) } for _, hook := range outgoingHooks { if err := a.Srv().Store.Webhook().DeleteOutgoing(hook.Id, now); err != nil { - mlog.Error("Encountered error deleting outgoing webhook", mlog.String("hook_id", hook.Id), mlog.Err(err)) + mlog.Warn("Encountered error deleting outgoing webhook", mlog.String("hook_id", hook.Id), mlog.Err(err)) } } diff --git a/app/cluster_discovery.go b/app/cluster_discovery.go index 036e8f2d20..63cab64b7b 100644 --- a/app/cluster_discovery.go +++ b/app/cluster_discovery.go @@ -37,17 +37,15 @@ func (a *App) NewClusterDiscoveryService() *ClusterDiscoveryService { func (cds *ClusterDiscoveryService) Start() { err := cds.srv.Store.ClusterDiscovery().Cleanup() if err != nil { - mlog.Error("ClusterDiscoveryService failed to cleanup the outdated cluster discovery information", mlog.Err(err)) + mlog.Warn("ClusterDiscoveryService failed to cleanup the outdated cluster discovery information", mlog.Err(err)) } exists, err := cds.srv.Store.ClusterDiscovery().Exists(&cds.ClusterDiscovery) if err != nil { - mlog.Error("ClusterDiscoveryService failed to check if row exists", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson()), mlog.Err(err)) - } else { - if exists { - if _, err := cds.srv.Store.ClusterDiscovery().Delete(&cds.ClusterDiscovery); err != nil { - mlog.Error("ClusterDiscoveryService failed to start clean", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson()), mlog.Err(err)) - } + mlog.Warn("ClusterDiscoveryService failed to check if row exists", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson()), mlog.Err(err)) + } else if exists { + if _, err := cds.srv.Store.ClusterDiscovery().Delete(&cds.ClusterDiscovery); err != nil { + mlog.Warn("ClusterDiscoveryService failed to start clean", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson()), mlog.Err(err)) } } @@ -62,7 +60,7 @@ func (cds *ClusterDiscoveryService) Start() { defer func() { ticker.Stop() if _, err := cds.srv.Store.ClusterDiscovery().Delete(&cds.ClusterDiscovery); err != nil { - mlog.Error("ClusterDiscoveryService failed to cleanup", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson()), mlog.Err(err)) + mlog.Warn("ClusterDiscoveryService failed to cleanup", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson()), mlog.Err(err)) } mlog.Debug("ClusterDiscoveryService ping writer stopped", mlog.String("ClusterDiscovery", cds.ClusterDiscovery.ToJson())) }() diff --git a/app/command.go b/app/command.go index 431db31ecb..4b5f207aee 100644 --- a/app/command.go +++ b/app/command.go @@ -185,7 +185,7 @@ func (a *App) ExecuteCommand(args *model.CommandArgs) (*model.CommandResponse, * clientTriggerId, triggerId, appErr := model.GenerateTriggerId(args.UserId, a.AsymmetricSigningKey()) if appErr != nil { - mlog.Error("error occurred in generating trigger Id for a user ", mlog.Err(appErr)) + mlog.Warn("error occurred in generating trigger Id for a user ", mlog.Err(appErr)) } args.TriggerId = triggerId diff --git a/app/config.go b/app/config.go index fd806ffbf8..83ec86cea3 100644 --- a/app/config.go +++ b/app/config.go @@ -138,7 +138,7 @@ func (s *Server) ensurePostActionCookieSecret() error { system.Value = string(v) // If we were able to save the key, use it, otherwise log the error. if err = s.Store.System().Save(system); err != nil { - mlog.Error("Failed to save PostActionCookieSecret", mlog.Err(err)) + mlog.Warn("Failed to save PostActionCookieSecret", mlog.Err(err)) } else { secret = newSecret } @@ -201,7 +201,7 @@ func (s *Server) ensureAsymmetricSigningKey() error { system.Value = string(v) // If we were able to save the key, use it, otherwise log the error. if err = s.Store.System().Save(system); err != nil { - mlog.Error("Failed to save AsymmetricSigningKey", mlog.Err(err)) + mlog.Warn("Failed to save AsymmetricSigningKey", mlog.Err(err)) } else { key = newKey } diff --git a/app/emoji.go b/app/emoji.go index a300986df9..5fca22b9e7 100644 --- a/app/emoji.go +++ b/app/emoji.go @@ -338,7 +338,7 @@ func imageToPaletted(img image.Image) *image.Paletted { func (a *App) deleteEmojiImage(id string) { if err := a.MoveFile(getEmojiImagePath(id), "emoji/"+id+"/image_deleted"); err != nil { - mlog.Error("Failed to rename image when deleting emoji", mlog.String("emoji_id", id)) + mlog.Warn("Failed to rename image when deleting emoji", mlog.String("emoji_id", id)) } } diff --git a/app/file.go b/app/file.go index d68576839d..84f416730e 100644 --- a/app/file.go +++ b/app/file.go @@ -762,7 +762,7 @@ func (t *UploadFileTask) preprocessImage() *model.AppError { if t.fileinfo.MimeType == "image/svg+xml" { svgInfo, err := parseSVG(t.teeInput) if err != nil { - mlog.Error("Failed to parse SVG", mlog.Err(err)) + mlog.Warn("Failed to parse SVG", mlog.Err(err)) } if svgInfo.Width > 0 && svgInfo.Height > 0 { t.fileinfo.Width = svgInfo.Width diff --git a/app/import_functions.go b/app/import_functions.go index bfc3dc340e..c8da7ff89b 100644 --- a/app/import_functions.go +++ b/app/import_functions.go @@ -530,11 +530,13 @@ func (a *App) importUser(data *UserImportData, dryRun bool) *model.AppError { if data.ProfileImage != nil { file, err := os.Open(*data.ProfileImage) if err != nil { - mlog.Error("Unable to open the profile image.", mlog.Any("err", err)) + mlog.Warn("Unable to open the profile image.", mlog.Err(err)) } defer file.Close() - if err := a.SetProfileImageFromMultiPartFile(savedUser.Id, file); err != nil { - mlog.Error("Unable to set the profile image from a file.", mlog.Any("err", err)) + if err == nil { + if err := a.SetProfileImageFromMultiPartFile(savedUser.Id, file); err != nil { + mlog.Warn("Unable to set the profile image from a file.", mlog.Err(err)) + } } } diff --git a/app/integration_action.go b/app/integration_action.go index ac194f3e72..566c9ea73b 100644 --- a/app/integration_action.go +++ b/app/integration_action.go @@ -537,7 +537,7 @@ func (a *App) buildWarnMetricMailtoLink(warnMetricId string, user *model.User) s registeredUsersCount, err := a.Srv().Store.User().Count(model.UserCountOptions{}) if err != nil { - mlog.Error("Error retrieving the number of registered users", mlog.Err(err)) + mlog.Warn("Error retrieving the number of registered users", mlog.Err(err)) } else { mailBody += utils.T("api.server.warn_metric.bot_response.mailto_registered_users_header", map[string]interface{}{"NoRegisteredUsers": registeredUsersCount}) mailBody += "\r\n" diff --git a/app/ldap.go b/app/ldap.go index 643edefdb6..8facf82651 100644 --- a/app/ldap.go +++ b/app/ldap.go @@ -108,7 +108,7 @@ func (a *App) SwitchEmailToLdap(email, password, code, ldapLoginId, ldapPassword a.Srv().Go(func() { if err := a.Srv().EmailService.SendSignInChangeEmail(user.Email, "AD/LDAP", user.Locale, a.GetSiteURL()); err != nil { - mlog.Error(err.Error()) + mlog.Error("Could not send sign in method changed e-mail", mlog.Err(err)) } }) @@ -154,7 +154,7 @@ func (a *App) SwitchLdapToEmail(ldapPassword, code, email, newPassword string) ( a.Srv().Go(func() { if err := a.Srv().EmailService.SendSignInChangeEmail(user.Email, T("api.templates.signin_change_email.body.method_email"), user.Locale, a.GetSiteURL()); err != nil { - mlog.Error(err.Error()) + mlog.Error("Could not send sign in method changed e-mail", mlog.Err(err)) } }) diff --git a/app/license.go b/app/license.go index d51aa66c1d..ed9637eb00 100644 --- a/app/license.go +++ b/app/license.go @@ -266,7 +266,7 @@ func (s *Server) GenerateRenewalToken(expiration time.Duration) (string, *model. if license == nil { // Clean renewal token if there is no license present if _, err := s.Store.System().PermanentDeleteByName(model.SYSTEM_LICENSE_RENEWAL_TOKEN); err != nil { - mlog.Error("error removing the renewal token", mlog.Err(err)) + mlog.Warn("error removing the renewal token", mlog.Err(err)) } return "", model.NewAppError("GenerateRenewalToken", "app.license.generate_renewal_token.no_license", nil, "", http.StatusBadRequest) } diff --git a/app/notification.go b/app/notification.go index a8acc94e58..5997f5e52e 100644 --- a/app/notification.go +++ b/app/notification.go @@ -225,7 +225,7 @@ func (a *App) SendNotifications(post *model.Post, team *model.Team, channel *mod //If email verification is required and user email is not verified don't send email. if *a.Config().EmailSettings.RequireEmailVerification && !profileMap[id].EmailVerified { - mlog.Error("Skipped sending notification email, address not verified.", mlog.String("user_email", profileMap[id].Email), mlog.String("user_id", id)) + mlog.Debug("Skipped sending notification email, address not verified.", mlog.String("user_email", profileMap[id].Email), mlog.String("user_id", id)) continue } diff --git a/app/notification_email.go b/app/notification_email.go index 7c9c00e37d..95afd75606 100644 --- a/app/notification_email.go +++ b/app/notification_email.go @@ -171,7 +171,11 @@ func (a *App) getNotificationEmailBody(recipient *model.User, post *model.Post, bodyPage = a.Srv().EmailService.newEmailTemplate("post_body_full", recipient.Locale) postMessage := a.GetMessageForNotification(post, translateFunc) postMessage = html.EscapeString(postMessage) - normalizedPostMessage := a.generateHyperlinkForChannels(postMessage, teamName, landingURL) + normalizedPostMessage, err := a.generateHyperlinkForChannels(postMessage, teamName, landingURL) + if err != nil { + mlog.Warn("Encountered error while generating hyperlink for channels", mlog.String("team_name", teamName), mlog.Err(err)) + normalizedPostMessage = postMessage + } bodyPage.Props["PostMessage"] = template.HTML(normalizedPostMessage) } else { bodyPage = a.Srv().EmailService.newEmailTemplate("post_body_generic", recipient.Locale) @@ -284,22 +288,20 @@ func getFormattedPostTime(user *model.User, post *model.Post, useMilitaryTime bo } } -func (a *App) generateHyperlinkForChannels(postMessage, teamName, teamURL string) string { +func (a *App) generateHyperlinkForChannels(postMessage, teamName, teamURL string) (string, *model.AppError) { team, err := a.GetTeamByName(teamName) if err != nil { - mlog.Error("Encountered error while looking up team by name", mlog.String("team_name", teamName), mlog.Err(err)) - return postMessage + return "", err } channelNames := model.ChannelMentions(postMessage) if len(channelNames) == 0 { - return postMessage + return postMessage, nil } channels, err := a.GetChannelsByNames(channelNames, team.Id) if err != nil { - mlog.Error("Encountered error while getting channels", mlog.Err(err)) - return postMessage + return "", err } visited := make(map[string]bool) @@ -311,7 +313,7 @@ func (a *App) generateHyperlinkForChannels(postMessage, teamName, teamURL string visited[ch.Id] = true } } - return postMessage + return postMessage, nil } func (s *Server) GetMessageForNotification(post *model.Post, translateFunc i18n.TranslateFunc) string { diff --git a/app/notification_email_test.go b/app/notification_email_test.go index 208fd76a5c..f40f89da66 100644 --- a/app/notification_email_test.go +++ b/app/notification_email_test.go @@ -684,7 +684,8 @@ func TestGenerateHyperlinkForChannelsPublic(t *testing.T) { channelStoreMock.On("GetByNames", "test", []string{ch.Name}, true).Return([]*model.Channel{ch}, nil) storeMock.On("Channel").Return(&channelStoreMock) - outMessage := th.App.generateHyperlinkForChannels(message+mention, teamName, teamURL) + outMessage, err := th.App.generateHyperlinkForChannels(message+mention, teamName, teamURL) + require.Nil(t, err) channelURL := teamURL + "/channels/" + ch.Name assert.Equal(t, message+""+mention+"", outMessage) } @@ -733,7 +734,8 @@ func TestGenerateHyperlinkForChannelsMultiPublic(t *testing.T) { channelStoreMock.On("GetByNames", "test", []string{ch.Name, ch2.Name, ch3.Name}, true).Return([]*model.Channel{ch, ch2, ch3}, nil) storeMock.On("Channel").Return(&channelStoreMock) - outMessage := th.App.generateHyperlinkForChannels(message, teamName, teamURL) + outMessage, err := th.App.generateHyperlinkForChannels(message, teamName, teamURL) + require.Nil(t, err) channelURL := teamURL + "/channels/" + ch.Name channelURL2 := teamURL + "/channels/" + ch2.Name channelURL3 := teamURL + "/channels/" + ch3.Name @@ -766,7 +768,8 @@ func TestGenerateHyperlinkForChannelsPrivate(t *testing.T) { channelStoreMock.On("GetByNames", "test", []string{ch.Name}, true).Return([]*model.Channel{ch}, nil) storeMock.On("Channel").Return(&channelStoreMock) - outMessage := th.App.generateHyperlinkForChannels(message, teamName, teamURL) + outMessage, err := th.App.generateHyperlinkForChannels(message, teamName, teamURL) + require.Nil(t, err) assert.Equal(t, message, outMessage) } diff --git a/app/notification_push.go b/app/notification_push.go index f7debcc39e..7355072769 100644 --- a/app/notification_push.go +++ b/app/notification_push.go @@ -322,7 +322,7 @@ func (hub *PushNotificationsHub) start() { case notificationTypeUpdateBadge: err = hub.app.updateMobileAppBadgeSync(notification.userId) default: - mlog.Error("Invalid notification type", mlog.String("notification_type", string(notification.notificationType))) + mlog.Debug("Invalid notification type", mlog.String("notification_type", string(notification.notificationType))) } if err != nil { diff --git a/app/oauth.go b/app/oauth.go index 72395b99a8..3e1632ca21 100644 --- a/app/oauth.go +++ b/app/oauth.go @@ -109,7 +109,7 @@ func (a *App) DeleteOAuthApp(appId string) *model.AppError { } if err := a.Srv().InvalidateAllCaches(); err != nil { - mlog.Error("error in invalidating cache", mlog.Err(err)) + mlog.Warn("error in invalidating cache", mlog.Err(err)) } return nil @@ -204,7 +204,7 @@ func (a *App) AllowOAuthAppAccessToUser(userId string, authRequest *model.Author } if err != nil { - mlog.Error("error getting oauth redirect uri", mlog.Err(err)) + mlog.Warn("error getting oauth redirect uri", mlog.Err(err)) return authRequest.RedirectUri + "?error=server_error&state=" + authRequest.State, nil } @@ -217,7 +217,7 @@ func (a *App) AllowOAuthAppAccessToUser(userId string, authRequest *model.Author } if nErr := a.Srv().Store.Preference().Save(&model.Preferences{authorizedApp}); nErr != nil { - mlog.Error("error saving store preference", mlog.Err(nErr)) + mlog.Warn("error saving store preference", mlog.Err(nErr)) return authRequest.RedirectUri + "?error=server_error&state=" + authRequest.State, nil } @@ -384,7 +384,7 @@ func (a *App) newSession(appName string, user *model.User) (*model.Session, *mod func (a *App) newSessionUpdateToken(appName string, accessData *model.AccessData, user *model.User) (*model.AccessResponse, *model.AppError) { // Remove the previous session if err := a.Srv().Store.Session().Remove(accessData.Token); err != nil { - mlog.Error("error removing access data token from session", mlog.Err(err)) + mlog.Warn("error removing access data token from session", mlog.Err(err)) } session, err := a.newSession(appName, user) @@ -816,7 +816,7 @@ func (a *App) AuthorizeOAuthUser(w http.ResponseWriter, r *http.Request, service appErr = a.DeleteToken(expectedToken) if appErr != nil { - mlog.Error("error deleting token", mlog.Err(appErr)) + mlog.Warn("error deleting token", mlog.Err(appErr)) } subpath, _ := utils.GetSubpathFromConfig(a.Config()) diff --git a/app/plugin.go b/app/plugin.go index 4baefec1d9..38768a588b 100644 --- a/app/plugin.go +++ b/app/plugin.go @@ -149,7 +149,7 @@ func (a *App) SyncPluginsActiveState() { } if err := a.notifyPluginStatusesChanged(); err != nil { - mlog.Error("failed to notify plugin status changed", mlog.Err(err)) + mlog.Warn("failed to notify plugin status changed", mlog.Err(err)) } } @@ -795,7 +795,7 @@ func (a *App) getPluginsFromFilePaths(fileStorePaths []string) map[string]*plugi if strings.HasSuffix(path, ".tar.gz.sig") { id := strings.TrimSuffix(filepath.Base(path), ".tar.gz.sig") if val, ok := pluginSignaturePathMap[id]; !ok { - mlog.Error("Unknown signature", mlog.String("path", path)) + mlog.Warn("Unknown signature", mlog.String("path", path)) } else { val.signaturePath = path } diff --git a/app/plugin_install.go b/app/plugin_install.go index 9a2e52b5dc..8cba380d4e 100644 --- a/app/plugin_install.go +++ b/app/plugin_install.go @@ -111,11 +111,11 @@ func (a *App) RemovePluginFromData(data model.PluginEventData) { mlog.Debug("Removing plugin as per cluster message", mlog.String("plugin_id", data.Id)) if err := a.removePluginLocally(data.Id); err != nil { - mlog.Error("Failed to remove plugin locally", mlog.Err(err), mlog.String("id", data.Id)) + mlog.Warn("Failed to remove plugin locally", mlog.Err(err), mlog.String("id", data.Id)) } if err := a.notifyPluginStatusesChanged(); err != nil { - mlog.Error("failed to notify plugin status changed", mlog.Err(err)) + mlog.Warn("failed to notify plugin status changed", mlog.Err(err)) } } @@ -161,11 +161,11 @@ func (a *App) installPlugin(pluginFile, signature io.ReadSeeker, installationStr ) if err := a.notifyPluginEnabled(manifest); err != nil { - mlog.Error("Failed notify plugin enabled", mlog.Err(err)) + mlog.Warn("Failed notify plugin enabled", mlog.Err(err)) } if err := a.notifyPluginStatusesChanged(); err != nil { - mlog.Error("Failed to notify plugin status changed", mlog.Err(err)) + mlog.Warn("Failed to notify plugin status changed", mlog.Err(err)) } return manifest, nil @@ -413,7 +413,7 @@ func (a *App) removePlugin(id string) *model.AppError { return model.NewAppError("removePlugin", "app.plugin.remove_bundle.app_error", nil, err.Error(), http.StatusInternalServerError) } if err = a.removeSignature(id); err != nil { - mlog.Error("Can't remove signature", mlog.Err(err)) + mlog.Warn("Can't remove signature", mlog.Err(err)) } a.notifyClusterPluginEvent( @@ -424,7 +424,7 @@ func (a *App) removePlugin(id string) *model.AppError { ) if err := a.notifyPluginStatusesChanged(); err != nil { - mlog.Error("Failed to notify plugin status changed", mlog.Err(err)) + mlog.Warn("Failed to notify plugin status changed", mlog.Err(err)) } return nil diff --git a/app/plugin_key_value_store.go b/app/plugin_key_value_store.go index 3364376777..33413afb3c 100644 --- a/app/plugin_key_value_store.go +++ b/app/plugin_key_value_store.go @@ -42,7 +42,7 @@ func (a *App) CompareAndSetPluginKey(pluginId string, key string, oldValue, newV func (a *App) SetPluginKeyWithOptions(pluginId string, key string, value []byte, options model.PluginKVSetOptions) (bool, *model.AppError) { if err := options.IsValid(); err != nil { - mlog.Error("Failed to set plugin key value with options", mlog.String("plugin_id", pluginId), mlog.String("key", key), mlog.Err(err)) + mlog.Debug("Failed to set plugin key value with options", mlog.String("plugin_id", pluginId), mlog.String("key", key), mlog.Err(err)) return false, err } @@ -60,7 +60,7 @@ func (a *App) SetPluginKeyWithOptions(pluginId string, key string, value []byte, // Clean up a previous entry using the hashed key, if it exists. if err := a.Srv().Store.Plugin().Delete(pluginId, getKeyHash(key)); err != nil { - mlog.Error("Failed to clean up previously hashed plugin key value", mlog.String("plugin_id", pluginId), mlog.String("key", key), mlog.Err(err)) + mlog.Warn("Failed to clean up previously hashed plugin key value", mlog.String("plugin_id", pluginId), mlog.String("key", key), mlog.Err(err)) } return updated, nil @@ -86,7 +86,7 @@ func (a *App) CompareAndDeletePluginKey(pluginId string, key string, oldValue [] // Clean up a previous entry using the hashed key, if it exists. if err := a.Srv().Store.Plugin().Delete(pluginId, getKeyHash(key)); err != nil { - mlog.Error("Failed to clean up previously hashed plugin key value", mlog.String("plugin_id", pluginId), mlog.String("key", key), mlog.Err(err)) + mlog.Warn("Failed to clean up previously hashed plugin key value", mlog.String("plugin_id", pluginId), mlog.String("key", key), mlog.Err(err)) } return deleted, nil diff --git a/app/plugin_signature.go b/app/plugin_signature.go index 8e75561c48..8cc9c2ad4d 100644 --- a/app/plugin_signature.go +++ b/app/plugin_signature.go @@ -85,7 +85,7 @@ func (a *App) VerifyPlugin(plugin, signature io.ReadSeeker) *model.AppError { for _, pk := range publicKeys { pkBytes, appErr := a.GetPublicKey(pk) if appErr != nil { - mlog.Error("Unable to get public key for ", mlog.String("filename", pk)) + mlog.Warn("Unable to get public key for ", mlog.String("filename", pk)) continue } publicKey := bytes.NewReader(pkBytes) diff --git a/app/post.go b/app/post.go index 3807d7570b..2ab13a5b7f 100644 --- a/app/post.go +++ b/app/post.go @@ -86,7 +86,7 @@ func (a *App) CreatePostAsUser(post *model.Post, currentSessionId string, setOnl _, fromBot := post.GetProps()["from_bot"] if !fromWebhook && !fromBot { if _, err := a.MarkChannelsAsViewed([]string{post.ChannelId}, post.UserId, currentSessionId); err != nil { - mlog.Error( + mlog.Warn( "Encountered error updating last viewed", mlog.String("channel_id", post.ChannelId), mlog.String("user_id", post.UserId), @@ -273,7 +273,7 @@ func (a *App) CreatePost(post *model.Post, channel *model.Channel, triggerWebhoo post.AddProp("attachments", attachmentsInterface) } if err != nil { - mlog.Error("Could not convert post attachments to map interface.", mlog.Err(err)) + mlog.Warn("Could not convert post attachments to map interface.", mlog.Err(err)) } } @@ -338,7 +338,7 @@ func (a *App) CreatePost(post *model.Post, channel *model.Channel, triggerWebhoo if len(post.FileIds) > 0 { if err = a.attachFilesToPost(post); err != nil { - mlog.Error("Encountered error attaching files to post", mlog.String("post_id", post.Id), mlog.Any("file_ids", post.FileIds), mlog.Err(err)) + mlog.Warn("Encountered error attaching files to post", mlog.String("post_id", post.Id), mlog.Any("file_ids", post.FileIds), mlog.Err(err)) } if a.Metrics() != nil { @@ -351,7 +351,7 @@ func (a *App) CreatePost(post *model.Post, channel *model.Channel, triggerWebhoo rpost = a.PreparePostForClient(rpost, true, false) if err := a.handlePostEvents(rpost, user, channel, triggerWebhooks, parentPostList, setOnline); err != nil { - mlog.Error("Failed to handle post events", mlog.Err(err)) + mlog.Warn("Failed to handle post events", mlog.Err(err)) } // Send any ephemeral posts after the post is created to ensure it shows up after the latest post created @@ -412,7 +412,7 @@ func (a *App) FillInPostProps(post *model.Post, channel *model.Channel) *model.A if mentioned.Type == model.CHANNEL_OPEN { team, err := a.Srv().Store.Team().Get(mentioned.TeamId) if err != nil { - mlog.Error("Failed to get team of the channel mention", mlog.String("team_id", channel.TeamId), mlog.String("channel_id", channel.Id), mlog.Err(err)) + mlog.Warn("Failed to get team of the channel mention", mlog.String("team_id", channel.TeamId), mlog.String("channel_id", channel.Id), mlog.Err(err)) continue } channelMentionsProp[mentioned.Name] = map[string]interface{}{ @@ -1161,7 +1161,7 @@ func (a *App) convertChannelNamesToChannelIds(channels []string, userId string, for idx, channelName := range channels { channel, err := a.parseAndFetchChannelIdByNameFromInFilter(channelName, userId, teamId, includeDeletedChannels) if err != nil { - mlog.Error("error getting channel id by name from in filter", mlog.Err(err)) + mlog.Warn("error getting channel id by name from in filter", mlog.Err(err)) continue } channels[idx] = channel.Id @@ -1171,11 +1171,12 @@ func (a *App) convertChannelNamesToChannelIds(channels []string, userId string, func (a *App) convertUserNameToUserIds(usernames []string) []string { for idx, username := range usernames { - if user, err := a.GetUserByUsername(username); err != nil { - mlog.Error("error getting user by username", mlog.String("user_name", username), mlog.Err(err)) - } else { - usernames[idx] = user.Id + user, err := a.GetUserByUsername(username) + if err != nil { + mlog.Warn("error getting user by username", mlog.String("user_name", username), mlog.Err(err)) + continue } + usernames[idx] = user.Id } return usernames } diff --git a/app/product_notices.go b/app/product_notices.go index d8af43be3b..2586cc5c6c 100644 --- a/app/product_notices.go +++ b/app/product_notices.go @@ -304,12 +304,12 @@ func (a *App) UpdateProductNotices() *model.AppError { var err error cachedPostCount, err = a.Srv().Store.Post().AnalyticsPostCount("", false, false) if err != nil { - mlog.Error("Failed to fetch post count", mlog.String("error", err.Error())) + mlog.Warn("Failed to fetch post count", mlog.String("error", err.Error())) } cachedUserCount, err = a.Srv().Store.User().Count(model.UserCountOptions{IncludeDeleted: true}) if err != nil { - mlog.Error("Failed to fetch user count", mlog.String("error", err.Error())) + mlog.Warn("Failed to fetch user count", mlog.String("error", err.Error())) } data, err := utils.GetUrlWithCache(url, ¬icesCache, skip) diff --git a/app/ratelimit.go b/app/ratelimit.go index 39c2151433..8b4562e2fe 100644 --- a/app/ratelimit.go +++ b/app/ratelimit.go @@ -77,14 +77,14 @@ func (rl *RateLimiter) GenerateKey(r *http.Request) string { func (rl *RateLimiter) RateLimitWriter(key string, w http.ResponseWriter) bool { limited, context, err := rl.throttledRateLimiter.RateLimit(key, 1) if err != nil { - mlog.Critical("Internal server error when rate limiting. Rate Limiting broken.", mlog.Err(err)) + mlog.Error("Internal server error when rate limiting. Rate Limiting broken.", mlog.Err(err)) return false } setRateLimitHeaders(w, context) if limited { - mlog.Error("Denied due to throttling settings code=429", mlog.String("key", key)) + mlog.Debug("Denied due to throttling settings code=429", mlog.String("key", key)) http.Error(w, "limit exceeded", 429) } @@ -93,9 +93,7 @@ func (rl *RateLimiter) RateLimitWriter(key string, w http.ResponseWriter) bool { func (rl *RateLimiter) UserIdRateLimit(userId string, w http.ResponseWriter) bool { if rl.useAuth { - if rl.RateLimitWriter(userId, w) { - return true - } + return rl.RateLimitWriter(userId, w) } return false } @@ -103,9 +101,8 @@ func (rl *RateLimiter) UserIdRateLimit(userId string, w http.ResponseWriter) boo func (rl *RateLimiter) RateLimitHandler(wrappedHandler http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { key := rl.GenerateKey(r) - limited := rl.RateLimitWriter(key, w) - if !limited { + if !rl.RateLimitWriter(key, w) { wrappedHandler.ServeHTTP(w, r) } }) diff --git a/app/server.go b/app/server.go index 9cc97a369c..d3c8e3bd6f 100644 --- a/app/server.go +++ b/app/server.go @@ -219,7 +219,7 @@ func NewServer(options ...Option) (*Server, error) { } if err := s.initLogging(); err != nil { - mlog.Error(err.Error()) + mlog.Error("Could not initiate logging", mlog.Err(err)) } // This is called after initLogging() to avoid a race condition. @@ -763,7 +763,7 @@ func (s *Server) StopHTTPServer() { } } -func (s *Server) Shutdown() error { +func (s *Server) Shutdown() { mlog.Info("Stopping Server...") defer sentry.Flush(2 * time.Second) @@ -776,13 +776,13 @@ func (s *Server) Shutdown() error { if s.tracer != nil { if err := s.tracer.Close(); err != nil { - mlog.Error("Unable to cleanly shutdown opentracing client", mlog.Err(err)) + mlog.Warn("Unable to cleanly shutdown opentracing client", mlog.Err(err)) } } err := s.telemetryService.Shutdown() if err != nil { - mlog.Error("Unable to cleanly shutdown telemetry client", mlog.Err(err)) + mlog.Warn("Unable to cleanly shutdown telemetry client", mlog.Err(err)) } s.StopHTTPServer() @@ -832,14 +832,14 @@ func (s *Server) Shutdown() error { if s.CacheProvider != nil { if err = s.CacheProvider.Close(); err != nil { - mlog.Error("Unable to cleanly shutdown cache", mlog.Err(err)) + mlog.Warn("Unable to cleanly shutdown cache", mlog.Err(err)) } } timeoutCtx, timeoutCancel := context.WithTimeout(context.Background(), time.Second*15) defer timeoutCancel() if err := mlog.Flush(timeoutCtx); err != nil { - mlog.Error("Error flushing logs", mlog.Err(err)) + mlog.Warn("Error flushing logs", mlog.Err(err)) } mlog.Info("Server stopped") @@ -848,8 +848,6 @@ func (s *Server) Shutdown() error { timeoutCtx2, timeoutCancel2 := context.WithTimeout(context.Background(), time.Second*5) defer timeoutCancel2() _ = mlog.ShutdownAdvancedLogging(timeoutCtx2) - - return nil } func (s *Server) Restart() error { @@ -1328,17 +1326,17 @@ func doCheckWarnMetricStatus(a *App) { numberOfActiveUsers, err0 := a.Srv().Store.User().Count(model.UserCountOptions{}) if err0 != nil { - mlog.Error("Error attempting to get active registered users.", mlog.Err(err0)) + mlog.Debug("Error attempting to get active registered users.", mlog.Err(err0)) } teamCount, err1 := a.Srv().Store.Team().AnalyticsTeamCount(false) if err1 != nil { - mlog.Error("Error attempting to get number of teams.", mlog.Err(err1)) + mlog.Debug("Error attempting to get number of teams.", mlog.Err(err1)) } openChannelCount, err2 := a.Srv().Store.Channel().AnalyticsTypeCount("", model.CHANNEL_OPEN) if err2 != nil { - mlog.Error("Error attempting to get number of public channels.", mlog.Err(err2)) + mlog.Debug("Error attempting to get number of public channels.", mlog.Err(err2)) } // If an account is created with a different email domain @@ -1347,7 +1345,7 @@ func doCheckWarnMetricStatus(a *App) { localDomainAccount := utils.GetHostnameFromSiteURL(*a.Srv().Config().ServiceSettings.SiteURL) isDiffEmailAccount, err3 := a.Srv().Store.User().AnalyticsGetExternalUsers(localDomainAccount) if err3 != nil { - mlog.Error("Error attempting to get number of private channels.", mlog.Err(err3)) + mlog.Debug("Error attempting to get number of private channels.", mlog.Err(err3)) } warnMetrics := []model.WarnMetric{} @@ -1381,7 +1379,7 @@ func doCheckWarnMetricStatus(a *App) { postsCount, err4 := a.Srv().Store.Post().AnalyticsPostCount("", false, false) if err4 != nil { - mlog.Error("Error attempting to get number of posts.", mlog.Err(err4)) + mlog.Debug("Error attempting to get number of posts.", mlog.Err(err4)) } if postsCount > model.WarnMetricsTable[model.SYSTEM_WARN_METRIC_NUMBER_OF_POSTS_2M].Limit && warnMetricStatusFromStore[model.SYSTEM_WARN_METRIC_NUMBER_OF_POSTS_2M] != model.WARN_METRIC_STATUS_RUNONCE { diff --git a/app/server_test.go b/app/server_test.go index f454a6fa1a..4c3d70c2e5 100644 --- a/app/server_test.go +++ b/app/server_test.go @@ -328,9 +328,7 @@ func TestPanicLog(t *testing.T) { client := &http.Client{Transport: tr} client.Get("https://localhost:" + strconv.Itoa(s.ListenAddr.Port) + "/panic") - - err = s.Shutdown() - require.NoError(t, err) + s.Shutdown() // Checking whether panic was logged var panicLogged = false diff --git a/app/session.go b/app/session.go index 6fb9627fbe..ef7bb47a5f 100644 --- a/app/session.go +++ b/app/session.go @@ -5,6 +5,7 @@ package app import ( "errors" + "fmt" "math" "net/http" "os" @@ -142,17 +143,14 @@ func (a *App) UpdateSessionsIsGuest(userId string, isGuest bool) { sessions, err := a.Srv().Store.Session().GetSessions(userId) if err != nil { mlog.Error("Unable to get user sessions", mlog.String("user_id", userId), mlog.Err(err)) + return } for _, session := range sessions { - if isGuest { - session.AddProp(model.SESSION_PROP_IS_GUEST, "true") - } else { - session.AddProp(model.SESSION_PROP_IS_GUEST, "false") - } + session.AddProp(model.SESSION_PROP_IS_GUEST, fmt.Sprintf("%t", isGuest)) err := a.Srv().Store.Session().UpdateProps(session) if err != nil { - mlog.Error("Unable to update isGuest session", mlog.Err(err)) + mlog.Warn("Unable to update isGuest session", mlog.Err(err)) continue } a.AddSessionToCache(session) @@ -264,8 +262,7 @@ func (a *App) RevokeSessionsForDeviceId(userId string, deviceId string, currentS if session.DeviceId == deviceId && session.Id != currentSessionId { mlog.Debug("Revoking sessionId for userId. Re-login with the same device Id", mlog.String("session_id", session.Id), mlog.String("user_id", userId)) if err := a.RevokeSession(session); err != nil { - // Soft error so we still remove the other sessions - mlog.Error(err.Error()) + mlog.Warn("Could not revoke session for device", mlog.String("device_id", deviceId), mlog.Err(err)) } } } @@ -326,7 +323,7 @@ func (a *App) UpdateLastActivityAtIfNeeded(session model.Session) { } if err := a.Srv().Store.Session().UpdateLastActivityAt(session.Id, now); err != nil { - mlog.Error("Failed to update LastActivityAt", mlog.String("user_id", session.UserId), mlog.String("session_id", session.Id), mlog.Err(err)) + mlog.Warn("Failed to update LastActivityAt", mlog.String("user_id", session.UserId), mlog.String("session_id", session.Id), mlog.Err(err)) } session.LastActivityAt = now diff --git a/app/status.go b/app/status.go index 1b4e867431..e00cf53f23 100644 --- a/app/status.go +++ b/app/status.go @@ -209,7 +209,7 @@ func (a *App) SetStatusOnline(userId string, manual bool) { if status.Status != oldStatus || status.Manual != oldManual || status.LastActivityAt-oldTime > model.STATUS_MIN_UPDATE_TIME { if broadcast { if err := a.Srv().Store.Status().SaveOrUpdate(status); err != nil { - mlog.Error("Failed to save status", mlog.String("user_id", userId), mlog.Err(err), mlog.String("user_id", userId)) + mlog.Warn("Failed to save status", mlog.String("user_id", userId), mlog.Err(err), mlog.String("user_id", userId)) } } else { if err := a.Srv().Store.Status().UpdateLastActivityAt(status.UserId, status.LastActivityAt); err != nil { @@ -302,7 +302,7 @@ func (a *App) SaveAndBroadcastStatus(status *model.Status) { a.AddStatusCache(status) if err := a.Srv().Store.Status().SaveOrUpdate(status); err != nil { - mlog.Error("Failed to save status", mlog.String("user_id", status.UserId), mlog.Err(err)) + mlog.Warn("Failed to save status", mlog.String("user_id", status.UserId), mlog.Err(err)) } a.BroadcastStatus(status) diff --git a/app/team.go b/app/team.go index 9bec52d614..29d7bbb484 100644 --- a/app/team.go +++ b/app/team.go @@ -619,13 +619,13 @@ func (a *App) AddUserToTeamByToken(userId string, tokenId string) (*model.Team, for _, channel := range channels { _, err := a.AddUserToChannel(user, channel) if err != nil { - mlog.Error("error adding user to channel", mlog.Err(err)) + mlog.Warn("Error adding user to channel", mlog.Err(err)) } } } if err := a.DeleteToken(token); err != nil { - return nil, err + mlog.Warn("Error while deleting token", mlog.Err(err)) } return team, nil @@ -784,7 +784,7 @@ func (a *App) JoinUserToTeam(team *model.Team, user *model.User, userRequestorId } if err := a.createInitialSidebarCategories(user.Id, team.Id); err != nil { - mlog.Error( + mlog.Warn( "Encountered an issue creating default sidebar categories.", mlog.String("user_id", user.Id), mlog.String("team_id", team.Id), @@ -797,7 +797,7 @@ func (a *App) JoinUserToTeam(team *model.Team, user *model.User, userRequestorId if !user.IsGuest() { // Soft error if there is an issue joining the default channels if err := a.JoinDefaultChannels(team.Id, user, shouldBeAdmin, userRequestorId); err != nil { - mlog.Error( + mlog.Warn( "Encountered an issue joining default channels.", mlog.String("user_id", user.Id), mlog.String("team_id", team.Id), @@ -1306,11 +1306,11 @@ func (a *App) LeaveTeam(team *model.Team, user *model.User, requestorId string) if *a.Config().ServiceSettings.ExperimentalEnableDefaultChannelLeaveJoinMessages { if requestorId == user.Id { if err = a.postLeaveTeamMessage(user, channel); err != nil { - mlog.Error("Failed to post join/leave message", mlog.Err(err)) + mlog.Warn("Failed to post join/leave message", mlog.Err(err)) } } else { if err = a.postRemoveFromTeamMessage(user, channel); err != nil { - mlog.Error("Failed to post join/leave message", mlog.Err(err)) + mlog.Warn("Failed to post join/leave message", mlog.Err(err)) } } } @@ -1865,7 +1865,7 @@ func (a *App) GetTeamIdFromQuery(query url.Values) (string, *model.AppError) { return team.Id, nil } // soft fail, so we still create user but don't auto-join team - mlog.Error("error getting team by inviteId.", mlog.String("invite_id", inviteId), mlog.Err(err)) + mlog.Warn("Error getting team by inviteId.", mlog.String("invite_id", inviteId), mlog.Err(err)) } return "", nil diff --git a/app/upload.go b/app/upload.go index f0f8dff45e..e70976ca45 100644 --- a/app/upload.go +++ b/app/upload.go @@ -69,17 +69,17 @@ func (a *App) runPluginsHook(info *model.FileInfo, file io.Reader) *model.AppErr written, err := a.WriteFile(r, tmpPath) if err != nil { if fileErr := a.RemoveFile(tmpPath); fileErr != nil { - mlog.Error("Failed to remove file", mlog.Err(fileErr)) + mlog.Warn("Failed to remove file", mlog.Err(fileErr)) } return err } if err = <-errChan; err != nil { if fileErr := a.RemoveFile(info.Path); fileErr != nil { - mlog.Error("Failed to remove file", mlog.Err(fileErr)) + mlog.Warn("Failed to remove file", mlog.Err(fileErr)) } if fileErr := a.RemoveFile(tmpPath); fileErr != nil { - mlog.Error("Failed to remove file", mlog.Err(fileErr)) + mlog.Warn("Failed to remove file", mlog.Err(fileErr)) } return err } @@ -92,7 +92,7 @@ func (a *App) runPluginsHook(info *model.FileInfo, file io.Reader) *model.AppErr } } else { if fileErr := a.RemoveFile(tmpPath); fileErr != nil { - mlog.Error("Failed to remove file", mlog.Err(fileErr)) + mlog.Warn("Failed to remove file", mlog.Err(fileErr)) } } @@ -297,7 +297,7 @@ func (a *App) UploadData(us *model.UploadSession, rd io.Reader) (*model.FileInfo // delete upload session if storeErr := a.Srv().Store.UploadSession().Delete(us.Id); storeErr != nil { - mlog.Error("Failed to delete UploadSession", mlog.Err(storeErr)) + mlog.Warn("Failed to delete UploadSession", mlog.Err(storeErr)) } return info, nil diff --git a/app/user.go b/app/user.go index 13ed467a19..de6383b3cd 100644 --- a/app/user.go +++ b/app/user.go @@ -105,13 +105,13 @@ func (a *App) CreateUserWithToken(user *model.User, token *model.Token) (*model. for _, channel := range channels { _, err := a.AddChannelMember(ruser.Id, channel, "", "") if err != nil { - mlog.Error("Failed to add channel member", mlog.Err(err)) + mlog.Warn("Failed to add channel member", mlog.Err(err)) } } } if err := a.DeleteToken(token); err != nil { - return nil, err + mlog.Warn("Error while deleting token", mlog.Err(err)) } return ruser, nil @@ -155,7 +155,7 @@ func (a *App) CreateUserWithInviteId(user *model.User, inviteId, redirect string a.AddDirectChannels(team.Id, ruser) if err := a.Srv().EmailService.sendWelcomeEmail(ruser.Id, ruser.Email, ruser.EmailVerified, ruser.Locale, a.GetSiteURL(), redirect); err != nil { - mlog.Error("Failed to send welcome email on create user with inviteId", mlog.Err(err)) + mlog.Warn("Failed to send welcome email on create user with inviteId", mlog.Err(err)) } return ruser, nil @@ -168,7 +168,7 @@ func (a *App) CreateUserAsAdmin(user *model.User, redirect string) (*model.User, } if err := a.Srv().EmailService.sendWelcomeEmail(ruser.Id, ruser.Email, ruser.EmailVerified, ruser.Locale, a.GetSiteURL(), redirect); err != nil { - mlog.Error("Failed to send welcome email on create admin user", mlog.Err(err)) + mlog.Warn("Failed to send welcome email on create admin user", mlog.Err(err)) } return ruser, nil @@ -192,7 +192,7 @@ func (a *App) CreateUserFromSignup(user *model.User, redirect string) (*model.Us } if err := a.Srv().EmailService.sendWelcomeEmail(ruser.Id, ruser.Email, ruser.EmailVerified, ruser.Locale, a.GetSiteURL(), redirect); err != nil { - mlog.Error("Failed to send welcome email on create user from signup", mlog.Err(err)) + mlog.Warn("Failed to send welcome email on create user from signup", mlog.Err(err)) } return ruser, nil @@ -321,13 +321,13 @@ func (a *App) createUser(user *model.User) (*model.User, *model.AppError) { if user.EmailVerified { if err := a.VerifyUserEmail(ruser.Id, user.Email); err != nil { - mlog.Error("Failed to set email verified", mlog.Err(err)) + mlog.Warn("Failed to set email verified", mlog.Err(err)) } } pref := model.Preference{UserId: ruser.Id, Category: model.PREFERENCE_CATEGORY_TUTORIAL_STEPS, Name: ruser.Id, Value: "0"} if err := a.Srv().Store.Preference().Save(&model.Preferences{pref}); err != nil { - mlog.Error("Encountered error saving tutorial preference", mlog.Err(err)) + mlog.Warn("Encountered error saving tutorial preference", mlog.Err(err)) } go a.UpdateViewedProductNoticesForNewUser(ruser.Id) @@ -401,7 +401,7 @@ func (a *App) CreateOAuthUser(service string, userData io.Reader, teamId string, err = a.AddDirectChannels(teamId, user) if err != nil { - mlog.Error("Failed to add direct channels", mlog.Err(err)) + mlog.Warn("Failed to add direct channels", mlog.Err(err)) } } @@ -930,14 +930,14 @@ func (a *App) SetDefaultProfileImage(user *model.User) *model.AppError { } if err := a.Srv().Store.User().ResetLastPictureUpdate(user.Id); err != nil { - mlog.Error("Failed to reset last picture update", mlog.Err(err)) + mlog.Warn("Failed to reset last picture update", mlog.Err(err)) } a.InvalidateCacheForUser(user.Id) updatedUser, appErr := a.GetUser(user.Id) if appErr != nil { - mlog.Error("Error in getting users profile forcing logout", mlog.String("user_id", user.Id), mlog.Err(appErr)) + mlog.Warn("Error in getting users profile forcing logout", mlog.String("user_id", user.Id), mlog.Err(appErr)) return nil } @@ -1013,7 +1013,7 @@ func (a *App) SetProfileImageFromFile(userId string, file io.Reader) *model.AppE } if err := a.Srv().Store.User().UpdateLastPictureUpdate(userId); err != nil { - mlog.Error("Error with updating last picture update", mlog.Err(err)) + mlog.Warn("Error with updating last picture update", mlog.Err(err)) } a.invalidateUserCacheAndPublish(userId) @@ -1485,7 +1485,7 @@ func (a *App) ResetPasswordFromToken(userSuppliedTokenString, newPassword string } if err := a.DeleteToken(token); err != nil { - mlog.Error("Failed to delete token", mlog.Err(err)) + mlog.Warn("Failed to delete token", mlog.Err(err)) } return nil @@ -1601,7 +1601,7 @@ func (a *App) UpdateUserRoles(userId string, newRoles string, sendWebSocketEvent if result := <-schan; result.NErr != nil { // soft error since the user roles were still updated - mlog.Error("Failed during updating user roles", mlog.Err(result.NErr)) + mlog.Warn("Failed during updating user roles", mlog.Err(result.NErr)) } a.InvalidateCacheForUser(userId) @@ -1792,7 +1792,7 @@ func (a *App) VerifyEmailFromToken(userSuppliedTokenString string) *model.AppErr } if err := a.DeleteToken(token); err != nil { - mlog.Error("Failed to delete token", mlog.Err(err)) + mlog.Warn("Failed to delete token", mlog.Err(err)) } return nil @@ -2207,13 +2207,13 @@ func (a *App) PromoteGuestToUser(user *model.User, requestorId string) *model.Ap for _, team := range userTeams { // Soft error if there is an issue joining the default channels if err := a.JoinDefaultChannels(team.Id, user, false, requestorId); err != nil { - mlog.Error("Failed to join default channels", mlog.String("user_id", user.Id), mlog.String("team_id", team.Id), mlog.String("requestor_id", requestorId), mlog.Err(err)) + mlog.Warn("Failed to join default channels", mlog.String("user_id", user.Id), mlog.String("team_id", team.Id), mlog.String("requestor_id", requestorId), mlog.Err(err)) } } promotedUser, err := a.GetUser(user.Id) if err != nil { - mlog.Error("Failed to get user on promote guest to user", mlog.Err(err)) + mlog.Warn("Failed to get user on promote guest to user", mlog.Err(err)) } else { a.sendUpdatedUserEvent(*promotedUser) a.UpdateSessionsIsGuest(promotedUser.Id, promotedUser.IsGuest()) @@ -2221,7 +2221,7 @@ func (a *App) PromoteGuestToUser(user *model.User, requestorId string) *model.Ap teamMembers, err := a.GetTeamMembersForUser(user.Id) if err != nil { - mlog.Error("Failed to get team members for user on promote guest to user", mlog.Err(err)) + mlog.Warn("Failed to get team members for user on promote guest to user", mlog.Err(err)) } for _, member := range teamMembers { @@ -2229,7 +2229,7 @@ func (a *App) PromoteGuestToUser(user *model.User, requestorId string) *model.Ap channelMembers, err := a.GetChannelMembersForUser(member.TeamId, user.Id) if err != nil { - mlog.Error("Failed to get channel members for user on promote guest to user", mlog.Err(err)) + mlog.Warn("Failed to get channel members for user on promote guest to user", mlog.Err(err)) } for _, member := range *channelMembers { @@ -2256,7 +2256,7 @@ func (a *App) DemoteUserToGuest(user *model.User) *model.AppError { demotedUser, err := a.GetUser(user.Id) if err != nil { - mlog.Error("Failed to get user on demote user to guest", mlog.Err(err)) + mlog.Warn("Failed to get user on demote user to guest", mlog.Err(err)) } else { a.sendUpdatedUserEvent(*demotedUser) a.UpdateSessionsIsGuest(demotedUser.Id, demotedUser.IsGuest()) @@ -2264,7 +2264,7 @@ func (a *App) DemoteUserToGuest(user *model.User) *model.AppError { teamMembers, err := a.GetTeamMembersForUser(user.Id) if err != nil { - mlog.Error("Failed to get team members for users on demote user to guest", mlog.Err(err)) + mlog.Warn("Failed to get team members for users on demote user to guest", mlog.Err(err)) } for _, member := range teamMembers { @@ -2272,7 +2272,7 @@ func (a *App) DemoteUserToGuest(user *model.User) *model.AppError { channelMembers, err := a.GetChannelMembersForUser(member.TeamId, user.Id) if err != nil { - mlog.Error("Failed to get channel members for users on demote user to guest", mlog.Err(err)) + mlog.Warn("Failed to get channel members for users on demote user to guest", mlog.Err(err)) } for _, member := range *channelMembers { diff --git a/app/web_conn.go b/app/web_conn.go index c48d41a09c..60b69e9eb2 100644 --- a/app/web_conn.go +++ b/app/web_conn.go @@ -7,6 +7,7 @@ import ( "bytes" "encoding/json" "fmt" + "net/http" "sync" "sync/atomic" "time" @@ -282,7 +283,12 @@ func (wc *WebConn) IsAuthenticated() bool { session, err := wc.App.GetSession(wc.GetSessionToken()) if err != nil { - mlog.Error("Invalid session.", mlog.Err(err)) + if err.StatusCode >= http.StatusBadRequest && err.StatusCode < http.StatusInternalServerError { + mlog.Debug("Invalid session.", mlog.Err(err)) + } else { + mlog.Error("Could not get session", mlog.String("session_token", wc.GetSessionToken()), mlog.Err(err)) + } + wc.SetSessionToken("") wc.SetSession(nil) wc.SetSessionExpiresAt(0) @@ -310,7 +316,7 @@ func (wc *WebConn) shouldSendEventToGuest(msg *model.WebSocketEvent) bool { case model.WEBSOCKET_EVENT_USER_UPDATED: user, ok := msg.GetData()["user"].(*model.User) if !ok { - mlog.Error("webhub.shouldSendEvent: user not found in message", mlog.Any("user", msg.GetData()["user"])) + mlog.Debug("webhub.shouldSendEvent: user not found in message", mlog.Any("user", msg.GetData()["user"])) return false } userId = user.Id @@ -413,7 +419,11 @@ func (wc *WebConn) isMemberOfTeam(teamId string) bool { if currentSession == nil || currentSession.Token == "" { session, err := wc.App.GetSession(wc.GetSessionToken()) if err != nil { - mlog.Error("Invalid session.", mlog.Err(err)) + if err.StatusCode >= http.StatusBadRequest && err.StatusCode < http.StatusInternalServerError { + mlog.Debug("Invalid session.", mlog.Err(err)) + } else { + mlog.Error("Could not get session", mlog.String("session_token", wc.GetSessionToken()), mlog.Err(err)) + } return false } wc.SetSession(session) diff --git a/app/websocket_router.go b/app/websocket_router.go index de77e2c407..203e9cefb1 100644 --- a/app/websocket_router.go +++ b/app/websocket_router.go @@ -95,7 +95,11 @@ func (wr *WebSocketRouter) ServeWebSocket(conn *WebConn, r *model.WebSocketReque } func returnWebSocketError(app *App, conn *WebConn, r *model.WebSocketRequest, err *model.AppError) { - mlog.Error( + logF := mlog.Error + if err.StatusCode >= http.StatusBadRequest && err.StatusCode < http.StatusInternalServerError { + logF = mlog.Debug + } + logF( "websocket routing error.", mlog.Int64("seq", r.Seq), mlog.String("user_id", conn.UserId),