From 686c2fbab7607d42183ae685a27ea3d7dce8c3f6 Mon Sep 17 00:00:00 2001 From: Christopher Speller Date: Fri, 27 Apr 2018 12:49:45 -0700 Subject: Structured logging (#8673) * Implementing structured logging * Changes to en.json to allow refactor to run. * Fixing global logger * Structured logger initalization. * Add caller. * Do some log redirection. * Auto refactor * Cleaning up l4g reference and removing dependancy. * Removing junk. * Copyright headers. * Fixing tests * Revert "Changes to en.json to allow refactor to run." This reverts commit fd8249e99bcad0231e6ea65cd77c32aae9a54026. * Fixing some auto refactor strangeness and typo. * Making keys more human readable. --- app/admin.go | 8 +-- app/analytics.go | 6 ++- app/app.go | 51 +++++++++++-------- app/app_test.go | 14 +++++- app/apptestlib.go | 31 ++++++------ app/authorization.go | 7 +-- app/auto_responder.go | 5 +- app/auto_users.go | 7 ++- app/channel.go | 44 ++++++++--------- app/cluster_discovery.go | 16 +++--- app/command.go | 6 +-- app/command_echo.go | 5 +- app/command_groupmsg.go | 4 +- app/command_invite.go | 7 +-- app/command_invite_people.go | 4 +- app/command_loadtest.go | 8 +-- app/command_msg.go | 8 +-- app/command_mute_test.go | 5 +- app/command_remove.go | 4 +- app/config.go | 8 +-- app/diagnostics.go | 8 +-- app/email.go | 8 +-- app/email_batching.go | 22 ++++----- app/emoji.go | 11 ++--- app/file.go | 40 +++++++-------- app/import.go | 19 ++++---- app/ldap.go | 9 ++-- app/license.go | 11 ++--- app/notification.go | 32 ++++++------ app/oauth.go | 11 +++-- app/plugin.go | 49 +++++++++---------- app/plugin/ldapextras/plugin.go | 4 +- app/post.go | 30 ++++++------ app/ratelimit.go | 7 +-- app/role.go | 3 +- app/security_update_check.go | 15 +++--- app/server.go | 34 ++++++++----- app/session.go | 15 +++--- app/slackimport.go | 105 ++++++++++++++++++++-------------------- app/status.go | 9 ++-- app/team.go | 10 ++-- app/user.go | 44 ++++++++--------- app/web_conn.go | 29 ++++++----- app/web_hub.go | 24 +++++---- app/webhook.go | 7 +-- app/websocket_router.go | 6 +-- 46 files changed, 421 insertions(+), 389 deletions(-) (limited to 'app') diff --git a/app/admin.go b/app/admin.go index 60b71505a..892e2d16b 100644 --- a/app/admin.go +++ b/app/admin.go @@ -13,7 +13,7 @@ import ( "net/http" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -137,7 +137,7 @@ func (a *App) InvalidateAllCaches() *model.AppError { } func (a *App) InvalidateAllCachesSkipSend() { - l4g.Info(utils.T("api.context.invalidate_all_caches")) + mlog.Info("Purging all caches") a.sessionCache.Purge() ClearStatusCache() a.Srv.Store.Channel().ClearCaches() @@ -209,7 +209,7 @@ func (a *App) SaveConfig(cfg *model.Config, sendConfigChangeClusterMessage bool) func (a *App) RecycleDatabaseConnection() { oldStore := a.Srv.Store - l4g.Warn(utils.T("api.admin.recycle_db_start.warn")) + mlog.Warn("Attempting to recycle the database connection.") a.Srv.Store = a.newStore() a.Jobs.Store = a.Srv.Store @@ -218,7 +218,7 @@ func (a *App) RecycleDatabaseConnection() { oldStore.Close() } - l4g.Warn(utils.T("api.admin.recycle_db_end.warn")) + mlog.Warn("Finished recycling the database connection.") } func (a *App) TestEmail(userId string, cfg *model.Config) *model.AppError { diff --git a/app/analytics.go b/app/analytics.go index f4e6fec95..7a32e78c1 100644 --- a/app/analytics.go +++ b/app/analytics.go @@ -4,7 +4,9 @@ package app import ( - l4g "github.com/alecthomas/log4go" + "fmt" + + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" ) @@ -22,7 +24,7 @@ func (a *App) GetAnalytics(name string, teamId string) (model.AnalyticsRows, *mo } else { systemUserCount = r.Data.(int64) if systemUserCount > int64(*a.Config().AnalyticsSettings.MaxUsersForStatistics) { - l4g.Debug("More than %v users on the system, intensive queries skipped", *a.Config().AnalyticsSettings.MaxUsersForStatistics) + mlog.Debug(fmt.Sprintf("More than %v users on the system, intensive queries skipped", *a.Config().AnalyticsSettings.MaxUsersForStatistics)) skipIntensiveQueries = true } } diff --git a/app/app.go b/app/app.go index 51ee37cbd..b31f67d6b 100644 --- a/app/app.go +++ b/app/app.go @@ -5,6 +5,7 @@ package app import ( "crypto/ecdsa" + "fmt" "html/template" "net" "net/http" @@ -13,13 +14,13 @@ import ( "sync" "sync/atomic" - l4g "github.com/alecthomas/log4go" "github.com/gorilla/mux" "github.com/pkg/errors" "github.com/mattermost/mattermost-server/einterfaces" ejobs "github.com/mattermost/mattermost-server/einterfaces/jobs" "github.com/mattermost/mattermost-server/jobs" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/plugin/pluginenv" "github.com/mattermost/mattermost-server/store" @@ -35,6 +36,8 @@ type App struct { Srv *Server + Log *mlog.Logger + PluginEnv *pluginenv.Environment PluginConfigListenerId string @@ -77,6 +80,7 @@ type App struct { sessionCache *utils.Cache configListenerId string licenseListenerId string + logListenerId string disableConfigWatch bool configWatcher *utils.ConfigWatcher asymmetricSigningKey *ecdsa.PrivateKey @@ -127,15 +131,23 @@ func New(options ...Option) (outApp *App, outErr error) { } model.AppErrorInit(utils.T) - // The first time we load config, clear any existing filters to allow the configuration - // changes to take effect. This is safe only because no one else is logging at this point. - l4g.Close() - if err := app.LoadConfig(app.configFile); err != nil { - // Re-initialize the default logger as we bail out. - l4g.Global = l4g.NewDefaultLogger(l4g.DEBUG) return nil, err } + + // Initalize logging + app.Log = mlog.NewLogger(utils.MloggerConfigFromLoggerConfig(&app.Config().LogSettings)) + + // Redirect default golang logger to this logger + mlog.RedirectStdLog(app.Log) + + // Use this app logger as the global logger (eventually remove all instances of global logging) + mlog.InitGlobalLogger(app.Log) + + app.logListenerId = app.AddConfigListener(func(_, after *model.Config) { + app.Log.ChangeLevels(utils.MloggerConfigFromLoggerConfig(&after.LogSettings)) + }) + app.EnableConfigWatch() app.LoadTimezones() @@ -166,7 +178,7 @@ func New(options ...Option) (outApp *App, outErr error) { }) app.regenerateClientConfig() - l4g.Info(utils.T("api.server.new_server.init.info")) + mlog.Info("Server is initializing...") app.initEnterprise() @@ -177,7 +189,7 @@ func New(options ...Option) (outApp *App, outErr error) { } if htmlTemplateWatcher, err := utils.NewHTMLTemplateWatcher("templates"); err != nil { - l4g.Error(utils.T("api.api.init.parsing_templates.error"), err) + mlog.Error(fmt.Sprintf("Failed to parse server templates %v", err)) } else { app.htmlTemplateWatcher = htmlTemplateWatcher } @@ -210,7 +222,7 @@ func (a *App) configOrLicenseListener() { func (a *App) Shutdown() { appCount-- - l4g.Info(utils.T("api.server.stop_server.stopping.info")) + mlog.Info("Stopping Server...") a.StopServer() a.HubStop() @@ -229,7 +241,8 @@ func (a *App) Shutdown() { a.RemoveConfigListener(a.configListenerId) a.RemoveLicenseListener(a.licenseListenerId) - l4g.Info(utils.T("api.server.stop_server.stopped.info")) + a.RemoveConfigListener(a.logListenerId) + mlog.Info("Server stopped") a.DisableConfigWatch() } @@ -499,7 +512,7 @@ func (a *App) HTTPClient(trustURLs bool) *http.Client { func (a *App) Handle404(w http.ResponseWriter, r *http.Request) { err := model.NewAppError("Handle404", "api.context.404.app_error", nil, "", http.StatusNotFound) - l4g.Debug("%v: code=404 ip=%v", r.URL.Path, utils.GetIpAddress(r)) + mlog.Debug(fmt.Sprintf("%v: code=404 ip=%v", r.URL.Path, utils.GetIpAddress(r))) utils.RenderWebAppError(w, r, err, a.AsymmetricSigningKey()) } @@ -511,7 +524,7 @@ func (a *App) DoAdvancedPermissionsMigration() { return } - l4g.Info("Migrating roles to database.") + mlog.Info("Migrating roles to database.") roles := model.MakeDefaultRoles() roles = utils.SetRolePermissionsFromConfig(roles, a.Config(), a.License() != nil) @@ -521,8 +534,8 @@ func (a *App) DoAdvancedPermissionsMigration() { if result := <-a.Srv.Store.Role().Save(role); result.Err != nil { // If this failed for reasons other than the role already existing, don't mark the migration as done. if result2 := <-a.Srv.Store.Role().GetByName(role.Name); result2.Err != nil { - l4g.Critical("Failed to migrate role to database.") - l4g.Critical(result.Err) + mlog.Critical("Failed to migrate role to database.") + mlog.Critical(fmt.Sprint(result.Err)) allSucceeded = false } else { // If the role already existed, check it is the same and update if not. @@ -534,8 +547,8 @@ func (a *App) DoAdvancedPermissionsMigration() { role.Id = fetchedRole.Id if result := <-a.Srv.Store.Role().Save(role); result.Err != nil { // Role is not the same, but failed to update. - l4g.Critical("Failed to migrate role to database.") - l4g.Critical(result.Err) + mlog.Critical("Failed to migrate role to database.") + mlog.Critical(fmt.Sprint(result.Err)) allSucceeded = false } } @@ -553,7 +566,7 @@ func (a *App) DoAdvancedPermissionsMigration() { } if result := <-a.Srv.Store.System().Save(&system); result.Err != nil { - l4g.Critical("Failed to mark advanced permissions migration as completed.") - l4g.Critical(result.Err) + mlog.Critical("Failed to mark advanced permissions migration as completed.") + mlog.Critical(fmt.Sprint(result.Err)) } } diff --git a/app/app_test.go b/app/app_test.go index a726fc2b5..ccf7faeeb 100644 --- a/app/app_test.go +++ b/app/app_test.go @@ -9,10 +9,10 @@ import ( "os" "testing" - l4g "github.com/alecthomas/log4go" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store/storetest" "github.com/mattermost/mattermost-server/utils" @@ -20,12 +20,22 @@ import ( func TestMain(m *testing.M) { flag.Parse() + + // Setup a global logger to catch tests logging outside of app context + // The global logger will be stomped by apps initalizing but that's fine for testing. Ideally this won't happen. + mlog.InitGlobalLogger(mlog.NewLogger(&mlog.LoggerConfiguration{ + EnableConsole: true, + ConsoleJson: true, + ConsoleLevel: "error", + EnableFile: false, + })) + utils.TranslationsPreInit() // In the case where a dev just wants to run a single test, it's faster to just use the default // store. if filter := flag.Lookup("test.run").Value.String(); filter != "" && filter != "." { - l4g.Info("-test.run used, not creating temporary containers") + mlog.Info("-test.run used, not creating temporary containers") os.Exit(m.Run()) } diff --git a/app/apptestlib.go b/app/apptestlib.go index a5c2db91c..626e932e8 100644 --- a/app/apptestlib.go +++ b/app/apptestlib.go @@ -11,9 +11,8 @@ import ( "path/filepath" "time" - l4g "github.com/alecthomas/log4go" - "github.com/mattermost/mattermost-server/einterfaces" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/plugin" "github.com/mattermost/mattermost-server/plugin/pluginenv" @@ -169,8 +168,8 @@ func (me *TestHelper) CreateTeam() *model.Team { utils.DisableDebugLogForTest() var err *model.AppError if team, err = me.App.CreateTeam(team); err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } @@ -192,8 +191,8 @@ func (me *TestHelper) CreateUser() *model.User { utils.DisableDebugLogForTest() var err *model.AppError if user, err = me.App.CreateUser(user); err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } @@ -219,8 +218,8 @@ func (me *TestHelper) createChannel(team *model.Team, channelType string) *model utils.DisableDebugLogForTest() var err *model.AppError if channel, err = me.App.CreateChannel(channel, true); err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } @@ -233,8 +232,8 @@ func (me *TestHelper) CreateDmChannel(user *model.User) *model.Channel { var err *model.AppError var channel *model.Channel if channel, err = me.App.CreateDirectChannel(me.BasicUser.Id, user.Id); err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } @@ -255,8 +254,8 @@ func (me *TestHelper) CreatePost(channel *model.Channel) *model.Post { utils.DisableDebugLogForTest() var err *model.AppError if post, err = me.App.CreatePost(post, channel, false); err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } @@ -269,8 +268,8 @@ func (me *TestHelper) LinkUserToTeam(user *model.User, team *model.Team) { err := me.App.JoinUserToTeam(team, user, "") if err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } @@ -283,8 +282,8 @@ func (me *TestHelper) AddUserToChannel(user *model.User, channel *model.Channel) member, err := me.App.AddUserToChannel(user, channel) if err != nil { - l4g.Error(err.Error()) - l4g.Close() + mlog.Error(err.Error()) + time.Sleep(time.Second) panic(err) } diff --git a/app/authorization.go b/app/authorization.go index 2187472f7..f281b3e65 100644 --- a/app/authorization.go +++ b/app/authorization.go @@ -4,10 +4,11 @@ package app import ( + "fmt" "net/http" "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" ) @@ -193,8 +194,8 @@ func (a *App) RolesGrantPermission(roleNames []string, permissionId string) bool if err != nil { // This should only happen if something is very broken. We can't realistically // recover the situation, so deny permission and log an error. - l4g.Error("Failed to get roles from database with role names: " + strings.Join(roleNames, ",")) - l4g.Error(err) + mlog.Error("Failed to get roles from database with role names: " + strings.Join(roleNames, ",")) + mlog.Error(fmt.Sprint(err)) return false } diff --git a/app/auto_responder.go b/app/auto_responder.go index 23402ecd4..aa7f243c4 100644 --- a/app/auto_responder.go +++ b/app/auto_responder.go @@ -4,8 +4,7 @@ package app import ( - l4g "github.com/alecthomas/log4go" - + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" ) @@ -28,7 +27,7 @@ func (a *App) SendAutoResponse(channel *model.Channel, receiver *model.User, roo } if _, err := a.CreatePost(autoResponderPost, channel, false); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } } diff --git a/app/auto_users.go b/app/auto_users.go index 8ed6767ad..b11f9c572 100644 --- a/app/auto_users.go +++ b/app/auto_users.go @@ -4,11 +4,10 @@ package app import ( + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" - - l4g "github.com/alecthomas/log4go" ) type AutoUserCreator struct { @@ -75,7 +74,7 @@ func (cfg *AutoUserCreator) createRandomUser() (*model.User, bool) { result, err := cfg.client.CreateUserWithInvite(user, "", "", cfg.team.InviteId) if err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) return nil, false } @@ -83,7 +82,7 @@ func (cfg *AutoUserCreator) createRandomUser() (*model.User, bool) { status := &model.Status{UserId: ruser.Id, Status: model.STATUS_ONLINE, Manual: false, LastActivityAt: model.GetMillis(), ActiveChannel: ""} if result := <-cfg.app.Srv.Store.Status().SaveOrUpdate(status); result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) return nil, false } diff --git a/app/channel.go b/app/channel.go index e7cd747c6..26e3d771c 100644 --- a/app/channel.go +++ b/app/channel.go @@ -9,7 +9,7 @@ import ( "strings" "time" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -60,17 +60,17 @@ func (a *App) JoinDefaultChannels(teamId string, user *model.User, channelRole s err = cmResult.Err } if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(user.Id, townSquare.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } if *a.Config().ServiceSettings.ExperimentalEnableDefaultChannelLeaveJoinMessages { if requestor == nil { if err := a.postJoinTeamMessage(user, townSquare); err != nil { - l4g.Error(utils.T("api.channel.post_user_add_remove_message_and_forget.error"), err) + mlog.Error(fmt.Sprint("Failed to post join/leave message", err)) } } else { if err := a.postAddToTeamMessage(requestor, user, townSquare, ""); err != nil { - l4g.Error(utils.T("api.channel.post_user_add_remove_message_and_forget.error"), err) + mlog.Error(fmt.Sprint("Failed to post join/leave message", err)) } } } @@ -93,16 +93,16 @@ func (a *App) JoinDefaultChannels(teamId string, user *model.User, channelRole s err = cmResult.Err } if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(user.Id, offTopic.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } if requestor == nil { if err := a.postJoinChannelMessage(user, offTopic); err != nil { - l4g.Error(utils.T("api.channel.post_user_add_remove_message_and_forget.error"), err) + mlog.Error(fmt.Sprint("Failed to post join/leave message", err)) } } else { if err := a.PostAddToChannelMessage(requestor, user, offTopic, ""); err != nil { - l4g.Error(utils.T("api.channel.post_user_add_remove_message_and_forget.error"), err) + mlog.Error(fmt.Sprint("Failed to post join/leave message", err)) } } @@ -174,7 +174,7 @@ func (a *App) CreateChannel(channel *model.Channel, addMember bool) (*model.Chan return nil, cmresult.Err } if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(channel.CreatorId, sc.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } a.InvalidateCacheForUser(channel.CreatorId) @@ -227,10 +227,10 @@ func (a *App) createDirectChannel(userId string, otherUserId string) (*model.Cha channel := result.Data.(*model.Channel) if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(userId, channel.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(otherUserId, channel.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } return channel, nil @@ -258,7 +258,7 @@ func (a *App) WaitForChannelMembership(channelId string, userId string) { } } - l4g.Error("WaitForChannelMembership giving up channelId=%v userId=%v", channelId, userId) + mlog.Error(fmt.Sprintf("WaitForChannelMembership giving up channelId=%v userId=%v", channelId, userId), mlog.String("user_id", userId)) } } @@ -329,7 +329,7 @@ func (a *App) createGroupChannel(userIds []string, creatorId string) (*model.Cha return nil, result.Err } if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(user.Id, channel.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } } @@ -413,19 +413,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 { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } if channel.Header != oldChannelHeader { if err := a.PostUpdateChannelHeaderMessage(userId, channel, oldChannelHeader, channel.Header); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } if channel.Purpose != oldChannelPurpose { if err := a.PostUpdateChannelPurposeMessage(userId, channel, oldChannelPurpose, channel.Purpose); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } @@ -536,21 +536,21 @@ func (a *App) DeleteChannel(channel *model.Channel, userId string) *model.AppErr } if _, err := a.CreatePost(post, channel, false); err != nil { - l4g.Error(utils.T("api.channel.delete_channel.failed_post.error"), err) + mlog.Error(fmt.Sprintf("Failed to post archive message %v", err)) } } now := model.GetMillis() for _, hook := range incomingHooks { if result := <-a.Srv.Store.Webhook().DeleteIncoming(hook.Id, now); result.Err != nil { - l4g.Error(utils.T("api.channel.delete_channel.incoming_webhook.error"), hook.Id) + mlog.Error(fmt.Sprintf("Encountered error deleting incoming webhook, id=%v", hook.Id)) } a.InvalidateCacheForWebhook(hook.Id) } for _, hook := range outgoingHooks { if result := <-a.Srv.Store.Webhook().DeleteOutgoing(hook.Id, now); result.Err != nil { - l4g.Error(utils.T("api.channel.delete_channel.outgoing_webhook.error"), hook.Id) + mlog.Error(fmt.Sprintf("Encountered error deleting outgoing webhook, id=%v", hook.Id)) } } @@ -594,13 +594,13 @@ func (a *App) addUserToChannel(user *model.User, channel *model.Channel, teamMem Roles: model.CHANNEL_USER_ROLE_ID, } if result := <-a.Srv.Store.Channel().SaveMember(newMember); result.Err != nil { - l4g.Error("Failed to add member user_id=%v channel_id=%v err=%v", user.Id, channel.Id, result.Err) + mlog.Error(fmt.Sprintf("Failed to add member user_id=%v channel_id=%v err=%v", user.Id, channel.Id, result.Err), mlog.String("user_id", user.Id)) return nil, model.NewAppError("AddUserToChannel", "api.channel.add_user.to.channel.failed.app_error", nil, "", http.StatusInternalServerError) } a.WaitForChannelMembership(channel.Id, user.Id) if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(user.Id, channel.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } a.InvalidateCacheForUser(user.Id) @@ -1449,10 +1449,10 @@ func (a *App) GetDirectChannel(userId1, userId2 string) (*model.Channel, *model. channel := result.Data.(*model.Channel) if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(userId1, channel.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } if result := <-a.Srv.Store.ChannelMemberHistory().LogJoinEvent(userId2, channel.Id, model.GetMillis()); result.Err != nil { - l4g.Warn("Failed to update ChannelMemberHistory table %v", result.Err) + mlog.Warn(fmt.Sprintf("Failed to update ChannelMemberHistory table %v", result.Err)) } return channel, nil diff --git a/app/cluster_discovery.go b/app/cluster_discovery.go index 2682425f5..f7443680c 100644 --- a/app/cluster_discovery.go +++ b/app/cluster_discovery.go @@ -7,7 +7,7 @@ import ( "fmt" "time" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" ) @@ -36,36 +36,36 @@ func (me *ClusterDiscoveryService) Start() { <-me.app.Srv.Store.ClusterDiscovery().Cleanup() if cresult := <-me.app.Srv.Store.ClusterDiscovery().Exists(&me.ClusterDiscovery); cresult.Err != nil { - l4g.Error(fmt.Sprintf("ClusterDiscoveryService failed to check if row exists for %v with err=%v", me.ClusterDiscovery.ToJson(), cresult.Err)) + mlog.Error(fmt.Sprintf("ClusterDiscoveryService failed to check if row exists for %v with err=%v", me.ClusterDiscovery.ToJson(), cresult.Err)) } else { if cresult.Data.(bool) { if u := <-me.app.Srv.Store.ClusterDiscovery().Delete(&me.ClusterDiscovery); u.Err != nil { - l4g.Error(fmt.Sprintf("ClusterDiscoveryService failed to start clean for %v with err=%v", me.ClusterDiscovery.ToJson(), u.Err)) + mlog.Error(fmt.Sprintf("ClusterDiscoveryService failed to start clean for %v with err=%v", me.ClusterDiscovery.ToJson(), u.Err)) } } } if result := <-me.app.Srv.Store.ClusterDiscovery().Save(&me.ClusterDiscovery); result.Err != nil { - l4g.Error(fmt.Sprintf("ClusterDiscoveryService failed to save for %v with err=%v", me.ClusterDiscovery.ToJson(), result.Err)) + mlog.Error(fmt.Sprintf("ClusterDiscoveryService failed to save for %v with err=%v", me.ClusterDiscovery.ToJson(), result.Err)) return } go func() { - l4g.Debug(fmt.Sprintf("ClusterDiscoveryService ping writer started for %v", me.ClusterDiscovery.ToJson())) + mlog.Debug(fmt.Sprintf("ClusterDiscoveryService ping writer started for %v", me.ClusterDiscovery.ToJson())) ticker := time.NewTicker(DISCOVERY_SERVICE_WRITE_PING) defer func() { ticker.Stop() if u := <-me.app.Srv.Store.ClusterDiscovery().Delete(&me.ClusterDiscovery); u.Err != nil { - l4g.Error(fmt.Sprintf("ClusterDiscoveryService failed to cleanup for %v with err=%v", me.ClusterDiscovery.ToJson(), u.Err)) + mlog.Error(fmt.Sprintf("ClusterDiscoveryService failed to cleanup for %v with err=%v", me.ClusterDiscovery.ToJson(), u.Err)) } - l4g.Debug(fmt.Sprintf("ClusterDiscoveryService ping writer stopped for %v", me.ClusterDiscovery.ToJson())) + mlog.Debug(fmt.Sprintf("ClusterDiscoveryService ping writer stopped for %v", me.ClusterDiscovery.ToJson())) }() for { select { case <-ticker.C: if u := <-me.app.Srv.Store.ClusterDiscovery().SetLastPingAt(&me.ClusterDiscovery); u.Err != nil { - l4g.Error(fmt.Sprintf("ClusterDiscoveryService failed to write ping for %v with err=%v", me.ClusterDiscovery.ToJson(), u.Err)) + mlog.Error(fmt.Sprintf("ClusterDiscoveryService failed to write ping for %v with err=%v", me.ClusterDiscovery.ToJson(), u.Err)) } case <-me.stop: return diff --git a/app/command.go b/app/command.go index 039952cf0..796d656a7 100644 --- a/app/command.go +++ b/app/command.go @@ -10,7 +10,7 @@ import ( "net/url" "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" goi18n "github.com/nicksnyder/go-i18n/i18n" @@ -207,7 +207,7 @@ func (a *App) ExecuteCommand(args *model.CommandArgs) (*model.CommandResponse, * teamCmds := result.Data.([]*model.Command) for _, cmd := range teamCmds { if trigger == cmd.Trigger { - l4g.Debug(fmt.Sprintf(utils.T("api.command.execute_command.debug"), trigger, args.UserId)) + mlog.Debug(fmt.Sprintf(utils.T("api.command.execute_command.debug"), trigger, args.UserId)) p := url.Values{} p.Set("token", cmd.Token) @@ -308,7 +308,7 @@ func (a *App) HandleCommandResponse(command *model.Command, args *model.CommandA response.Attachments = a.ProcessSlackAttachments(response.Attachments) if _, err := a.CreateCommandPost(post, args.TeamId, response); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } return response, nil diff --git a/app/command_echo.go b/app/command_echo.go index 9fef8a0a9..f0851964b 100644 --- a/app/command_echo.go +++ b/app/command_echo.go @@ -4,11 +4,12 @@ package app import ( + "fmt" "strconv" "strings" "time" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -89,7 +90,7 @@ func (me *EchoProvider) DoCommand(a *App, args *model.CommandArgs, message strin time.Sleep(time.Duration(delay) * time.Second) if _, err := a.CreatePostMissingChannel(post, true); err != nil { - l4g.Error(args.T("api.command_echo.create.app_error"), err) + mlog.Error(fmt.Sprintf("Unable to create /echo post, err=%v", err)) } }) diff --git a/app/command_groupmsg.go b/app/command_groupmsg.go index 32ad431ff..0e783e1a8 100644 --- a/app/command_groupmsg.go +++ b/app/command_groupmsg.go @@ -7,7 +7,7 @@ import ( "fmt" "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -95,7 +95,7 @@ func (me *groupmsgProvider) DoCommand(a *App, args *model.CommandArgs, message s groupChannel, channelErr := a.CreateGroupChannel(targetUsersSlice, args.UserId) if channelErr != nil { - l4g.Error(channelErr.Error()) + mlog.Error(channelErr.Error()) return &model.CommandResponse{Text: args.T("api.command_groupmsg.group_fail.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } diff --git a/app/command_invite.go b/app/command_invite.go index ce443bf3d..9045365ad 100644 --- a/app/command_invite.go +++ b/app/command_invite.go @@ -4,9 +4,10 @@ package app import ( + "fmt" "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -41,7 +42,7 @@ func (me *InviteProvider) DoCommand(a *App, args *model.CommandArgs, message str return &model.CommandResponse{Text: args.T("api.command_invite.missing_message.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } - l4g.Debug(message) + mlog.Debug(fmt.Sprint(message)) splitMessage := strings.SplitN(message, " ", 2) targetUsername := splitMessage[0] @@ -49,7 +50,7 @@ func (me *InviteProvider) DoCommand(a *App, args *model.CommandArgs, message str var userProfile *model.User if result := <-a.Srv.Store.User().GetByUsername(targetUsername); result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) return &model.CommandResponse{Text: args.T("api.command_invite.missing_user.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } else { userProfile = result.Data.(*model.User) diff --git a/app/command_invite_people.go b/app/command_invite_people.go index e463bd37c..e5ff5a316 100644 --- a/app/command_invite_people.go +++ b/app/command_invite_people.go @@ -6,7 +6,7 @@ package app import ( "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -63,7 +63,7 @@ func (me *InvitePeopleProvider) DoCommand(a *App, args *model.CommandArgs, messa } if err := a.InviteNewUsersToTeam(emailList, args.TeamId, args.UserId); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) return &model.CommandResponse{ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL, Text: args.T("api.command.invite_people.fail")} } diff --git a/app/command_loadtest.go b/app/command_loadtest.go index e43a7113f..a4a8f003a 100644 --- a/app/command_loadtest.go +++ b/app/command_loadtest.go @@ -10,7 +10,7 @@ import ( "strconv" "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" goi18n "github.com/nicksnyder/go-i18n/i18n" @@ -177,10 +177,10 @@ func (me *LoadTestProvider) SetupCommand(a *App, args *model.CommandArgs, messag if !err { return &model.CommandResponse{Text: "Failed to create testing environment", ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } else { - l4g.Info("Testing environment created") + mlog.Info("Testing environment created") for i := 0; i < len(environment.Teams); i++ { - l4g.Info("Team Created: " + environment.Teams[i].Name) - l4g.Info("\t User to login: " + environment.Environments[i].Users[0].Email + ", " + USER_PASSWORD) + mlog.Info("Team Created: " + environment.Teams[i].Name) + mlog.Info("\t User to login: " + environment.Environments[i].Users[0].Email + ", " + USER_PASSWORD) } } } else { diff --git a/app/command_msg.go b/app/command_msg.go index cf0e90c74..6877c10d6 100644 --- a/app/command_msg.go +++ b/app/command_msg.go @@ -6,7 +6,7 @@ package app import ( "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -50,7 +50,7 @@ func (me *msgProvider) DoCommand(a *App, args *model.CommandArgs, message string var userProfile *model.User if result := <-a.Srv.Store.User().GetByUsername(targetUsername); result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) return &model.CommandResponse{Text: args.T("api.command_msg.missing.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } else { userProfile = result.Data.(*model.User) @@ -67,13 +67,13 @@ func (me *msgProvider) DoCommand(a *App, args *model.CommandArgs, message string if channel := <-a.Srv.Store.Channel().GetByName(args.TeamId, channelName, true); channel.Err != nil { if channel.Err.Id == "store.sql_channel.get_by_name.missing.app_error" { if directChannel, err := a.CreateDirectChannel(args.UserId, userProfile.Id); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) return &model.CommandResponse{Text: args.T("api.command_msg.dm_fail.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } else { targetChannelId = directChannel.Id } } else { - l4g.Error(channel.Err.Error()) + mlog.Error(channel.Err.Error()) return &model.CommandResponse{Text: args.T("api.command_msg.dm_fail.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } } else { diff --git a/app/command_mute_test.go b/app/command_mute_test.go index 9f82c48cc..18ced3ddf 100644 --- a/app/command_mute_test.go +++ b/app/command_mute_test.go @@ -4,11 +4,12 @@ package app import ( + "testing" + "time" + "github.com/mattermost/mattermost-server/model" "github.com/nicksnyder/go-i18n/i18n" "github.com/stretchr/testify/assert" - "testing" - "time" ) func TestMuteCommandNoChannel(t *testing.T) { diff --git a/app/command_remove.go b/app/command_remove.go index a9c21e2d5..3671a2063 100644 --- a/app/command_remove.go +++ b/app/command_remove.go @@ -6,9 +6,9 @@ package app import ( "strings" - l4g "github.com/alecthomas/log4go" goi18n "github.com/nicksnyder/go-i18n/i18n" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" ) @@ -93,7 +93,7 @@ func doCommand(a *App, args *model.CommandArgs, message string) *model.CommandRe var userProfile *model.User if result := <-a.Srv.Store.User().GetByUsername(targetUsername); result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) return &model.CommandResponse{Text: args.T("api.command_remove.missing.app_error"), ResponseType: model.COMMAND_RESPONSE_TYPE_EPHEMERAL} } else { userProfile = result.Data.(*model.User) diff --git a/app/config.go b/app/config.go index 75d38e24a..b4fbfe725 100644 --- a/app/config.go +++ b/app/config.go @@ -17,8 +17,7 @@ import ( "strconv" "strings" - l4g "github.com/alecthomas/log4go" - + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -60,9 +59,6 @@ func (a *App) LoadConfig(configFile string) *model.AppError { a.configFile = configPath - utils.ConfigureLog(&cfg.LogSettings) - l4g.Info("Using config file at %s", configPath) - a.config.Store(cfg) a.envConfig = envConfig @@ -101,7 +97,7 @@ func (a *App) EnableConfigWatch() { a.ReloadConfig() }) if err != nil { - l4g.Error(err) + mlog.Error(fmt.Sprint(err)) } a.configWatcher = configWatcher } diff --git a/app/diagnostics.go b/app/diagnostics.go index 6e9adbf3c..cda0814ca 100644 --- a/app/diagnostics.go +++ b/app/diagnostics.go @@ -5,11 +5,10 @@ package app import ( "encoding/json" - "log" - "os" "runtime" "sync/atomic" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/segmentio/analytics-go" ) @@ -69,12 +68,12 @@ func (a *App) SendDailyDiagnostics() { func (a *App) initDiagnostics(endpoint string) { if client == nil { client = analytics.New(SEGMENT_KEY) + client.Logger = a.Log.StdLog(mlog.String("source", "segment")) // For testing if endpoint != "" { client.Endpoint = endpoint client.Verbose = true client.Size = 1 - client.Logger = log.New(os.Stdout, "segment ", log.LstdFlags) } client.Identify(&analytics.Identify{ UserId: a.DiagnosticId(), @@ -299,10 +298,11 @@ func (a *App) trackConfig() { a.SendDiagnostic(TRACK_CONFIG_LOG, map[string]interface{}{ "enable_console": cfg.LogSettings.EnableConsole, "console_level": cfg.LogSettings.ConsoleLevel, + "console_json": *cfg.LogSettings.ConsoleJson, "enable_file": cfg.LogSettings.EnableFile, "file_level": cfg.LogSettings.FileLevel, + "file_json": cfg.LogSettings.FileJson, "enable_webhook_debugging": cfg.LogSettings.EnableWebhookDebugging, - "isdefault_file_format": isDefault(cfg.LogSettings.FileFormat, ""), "isdefault_file_location": isDefault(cfg.LogSettings.FileLocation, ""), }) diff --git a/app/email.go b/app/email.go index 7a50fd82a..aa05cefdb 100644 --- a/app/email.go +++ b/app/email.go @@ -9,9 +9,9 @@ import ( "net/http" - l4g "github.com/alecthomas/log4go" "github.com/nicksnyder/go-i18n/i18n" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -282,17 +282,17 @@ func (a *App) SendInviteEmails(team *model.Team, senderName string, invites []st data := model.MapToJson(props) if result := <-a.Srv.Store.Token().Save(token); result.Err != nil { - l4g.Error(utils.T("api.team.invite_members.send.error"), result.Err) + mlog.Error(fmt.Sprintf("Failed to send invite email successfully err=%v", result.Err)) continue } bodyPage.Props["Link"] = fmt.Sprintf("%s/signup_user_complete/?d=%s&t=%s", siteURL, url.QueryEscape(data), url.QueryEscape(token.Token)) if !a.Config().EmailSettings.SendEmailNotifications { - l4g.Info(utils.T("api.team.invite_members.sending.info"), invite, bodyPage.Props["Link"]) + mlog.Info(fmt.Sprintf("sending invitation to %v %v", invite, bodyPage.Props["Link"])) } if err := a.SendMail(invite, subject, bodyPage.Render()); err != nil { - l4g.Error(utils.T("api.team.invite_members.send.error"), err) + mlog.Error(fmt.Sprintf("Failed to send invite email successfully err=%v", err)) } } } diff --git a/app/email_batching.go b/app/email_batching.go index 07adda674..e1ea7abb5 100644 --- a/app/email_batching.go +++ b/app/email_batching.go @@ -10,12 +10,12 @@ import ( "sync" "time" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" "net/http" - l4g "github.com/alecthomas/log4go" "github.com/nicksnyder/go-i18n/i18n" ) @@ -41,7 +41,7 @@ func (a *App) AddNotificationEmailToBatch(user *model.User, post *model.Post, te } if !a.EmailBatching.Add(user, post, team) { - l4g.Error(utils.T("api.email_batching.add_notification_email_to_batch.channel_full.app_error")) + mlog.Error("Email batching job's receiving channel was full. Please increase the EmailBatchingBufferSize.") return model.NewAppError("AddNotificationEmailToBatch", "api.email_batching.add_notification_email_to_batch.channel_full.app_error", nil, "", http.StatusInternalServerError) } @@ -71,7 +71,7 @@ func NewEmailBatchingJob(a *App, bufferSize int) *EmailBatchingJob { } func (job *EmailBatchingJob) Start() { - l4g.Debug(utils.T("api.email_batching.start.starting"), *job.app.Config().EmailSettings.EmailBatchingInterval) + mlog.Debug(fmt.Sprintf("Email batching job starting. Checking for pending emails every %v seconds.", *job.app.Config().EmailSettings.EmailBatchingInterval)) newTask := model.CreateRecurringTask(EMAIL_BATCHING_TASK_NAME, job.CheckPendingEmails, time.Duration(*job.app.Config().EmailSettings.EmailBatchingInterval)*time.Second) job.taskMutex.Lock() @@ -107,7 +107,7 @@ func (job *EmailBatchingJob) CheckPendingEmails() { // without actually sending emails job.checkPendingNotifications(time.Now(), job.app.sendBatchedEmailNotification) - l4g.Debug(utils.T("api.email_batching.check_pending_emails.finished_running"), len(job.pendingNotifications)) + mlog.Debug(fmt.Sprintf("Email batching job ran. %v user(s) still have notifications pending.", len(job.pendingNotifications))) } func (job *EmailBatchingJob) handleNewNotifications() { @@ -141,7 +141,7 @@ func (job *EmailBatchingJob) checkPendingNotifications(now time.Time, handler fu } tchan := job.app.Srv.Store.Team().GetByName(notifications[0].teamName) if result := <-tchan; result.Err != nil { - l4g.Error("Unable to find Team id for notification", result.Err) + mlog.Error(fmt.Sprint("Unable to find Team id for notification", result.Err)) continue } else if team, ok := result.Data.(*model.Team); ok { inspectedTeamNames[notification.teamName] = team.Id @@ -151,12 +151,12 @@ func (job *EmailBatchingJob) checkPendingNotifications(now time.Time, handler fu // all queued notifications mchan := job.app.Srv.Store.Channel().GetMembersForUser(inspectedTeamNames[notification.teamName], userId) if result := <-mchan; result.Err != nil { - l4g.Error("Unable to find ChannelMembers for user", result.Err) + mlog.Error(fmt.Sprint("Unable to find ChannelMembers for user", result.Err)) continue } else if channelMembers, ok := result.Data.(*model.ChannelMembers); ok { for _, channelMember := range *channelMembers { if channelMember.LastViewedAt >= batchStartTime { - l4g.Debug("Deleted notifications for user %s", userId) + mlog.Debug(fmt.Sprintf("Deleted notifications for user %s", userId), mlog.String("user_id", userId)) delete(job.pendingNotifications, userId) break } @@ -198,7 +198,7 @@ func (a *App) sendBatchedEmailNotification(userId string, notifications []*batch var user *model.User if result := <-uchan; result.Err != nil { - l4g.Warn("api.email_batching.send_batched_email_notification.user.app_error") + mlog.Warn("api.email_batching.send_batched_email_notification.user.app_error") return } else { user = result.Data.(*model.User) @@ -212,7 +212,7 @@ func (a *App) sendBatchedEmailNotification(userId string, notifications []*batch var sender *model.User schan := a.Srv.Store.User().Get(notification.post.UserId) if result := <-schan; result.Err != nil { - l4g.Warn(utils.T("api.email_batching.render_batched_post.sender.app_error")) + mlog.Warn("Unable to find sender of post for batched email notification") continue } else { sender = result.Data.(*model.User) @@ -221,7 +221,7 @@ func (a *App) sendBatchedEmailNotification(userId string, notifications []*batch var channel *model.Channel cchan := a.Srv.Store.Channel().Get(notification.post.ChannelId, true) if result := <-cchan; result.Err != nil { - l4g.Warn(utils.T("api.email_batching.render_batched_post.channel.app_error")) + mlog.Warn("Unable to find channel of post for batched email notification") continue } else { channel = result.Data.(*model.Channel) @@ -250,7 +250,7 @@ func (a *App) sendBatchedEmailNotification(userId string, notifications []*batch body.Props["BodyText"] = translateFunc("api.email_batching.send_batched_email_notification.body_text", len(notifications)) if err := a.SendMail(user.Email, subject, body.Render()); err != nil { - l4g.Warn(utils.T("api.email_batchings.send_batched_email_notification.send.app_error"), user.Email, err) + mlog.Warn(fmt.Sprint("api.email_batchings.send_batched_email_notification.send.app_error FIXME: NOT FOUND IN TRANSLATIONS FILE", user.Email, err)) } } diff --git a/app/emoji.go b/app/emoji.go index eebe59ccf..f48501cf9 100644 --- a/app/emoji.go +++ b/app/emoji.go @@ -5,6 +5,7 @@ package app import ( "bytes" + "fmt" "image" "image/draw" "image/gif" @@ -14,13 +15,11 @@ import ( "mime/multipart" "net/http" - l4g "github.com/alecthomas/log4go" - "image/color/palette" "github.com/disintegration/imaging" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" - "github.com/mattermost/mattermost-server/utils" ) const ( @@ -242,13 +241,13 @@ 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 { - l4g.Error("Failed to rename image when deleting emoji %v", id) + mlog.Error(fmt.Sprintf("Failed to rename image when deleting emoji %v", id)) } } func (a *App) deleteReactionsForEmoji(emojiName string) { if result := <-a.Srv.Store.Reaction().DeleteAllWithEmojiName(emojiName); result.Err != nil { - l4g.Warn(utils.T("api.emoji.delete.delete_reactions.app_error"), emojiName) - l4g.Warn(result.Err) + mlog.Warn(fmt.Sprintf("Unable to delete reactions when deleting emoji with emoji name %v", emojiName)) + mlog.Warn(fmt.Sprint(result.Err)) } } diff --git a/app/file.go b/app/file.go index 06ee61c92..a1addd7ac 100644 --- a/app/file.go +++ b/app/file.go @@ -22,11 +22,11 @@ import ( "sync" "time" - l4g "github.com/alecthomas/log4go" "github.com/disintegration/imaging" "github.com/rwcarlsen/goexif/exif" _ "golang.org/x/image/bmp" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -98,7 +98,7 @@ func (a *App) GetInfoForFilename(post *model.Post, teamId string, filename strin // Find the path from the Filename of the form /{channelId}/{userId}/{uid}/{nameWithExtension} split := strings.SplitN(filename, "/", 5) if len(split) < 5 { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.unexpected_filename.error"), post.Id, filename) + mlog.Error(fmt.Sprintf("Unable to decipher filename when migrating post to use FileInfos, post_id=%v, filename=%v", post.Id, filename), mlog.String("post_id", post.Id)) return nil } @@ -108,7 +108,7 @@ func (a *App) GetInfoForFilename(post *model.Post, teamId string, filename strin name, _ := url.QueryUnescape(split[4]) if split[0] != "" || split[1] != post.ChannelId || split[2] != post.UserId || strings.Contains(split[4], "/") { - l4g.Warn(utils.T("api.file.migrate_filenames_to_file_infos.mismatched_filename.warn"), post.Id, post.ChannelId, post.UserId, filename) + mlog.Warn(fmt.Sprintf("Found an unusual filename when migrating post to use FileInfos, post_id=%v, channel_id=%v, user_id=%v, filename=%v", post.Id, post.ChannelId, post.UserId, filename), mlog.String("post_id", post.Id)) } pathPrefix := fmt.Sprintf("teams/%s/channels/%s/users/%s/%s/", teamId, channelId, userId, oldId) @@ -117,13 +117,13 @@ func (a *App) GetInfoForFilename(post *model.Post, teamId string, filename strin // Open the file and populate the fields of the FileInfo var info *model.FileInfo if data, err := a.ReadFile(path); err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.file_not_found.error"), post.Id, filename, path, err) + mlog.Error(fmt.Sprint("api.file.migrate_filenames_to_file_infos.file_not_found.error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, filename, path, err), mlog.String("post_id", post.Id)) return nil } else { var err *model.AppError info, err = model.GetInfoForBytes(name, data) if err != nil { - l4g.Warn(utils.T("api.file.migrate_filenames_to_file_infos.info.app_error"), post.Id, filename, err) + mlog.Warn(fmt.Sprintf("Unable to fully decode file info when migrating post to use FileInfos, post_id=%v, filename=%v, err=%v", post.Id, filename, err), mlog.String("post_id", post.Id)) } } @@ -151,7 +151,7 @@ func (a *App) FindTeamIdForFilename(post *model.Post, filename string) string { // This post is in a direct channel so we need to figure out what team the files are stored under. if result := <-a.Srv.Store.Team().GetTeamsByUserId(post.UserId); result.Err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.teams.app_error"), post.Id, result.Err) + mlog.Error(fmt.Sprintf("Unable to get teams when migrating post to use FileInfos, post_id=%v, err=%v", post.Id, result.Err), mlog.String("post_id", post.Id)) } else if teams := result.Data.([]*model.Team); len(teams) == 1 { // The user has only one team so the post must've been sent from it return teams[0].Id @@ -173,7 +173,7 @@ var fileMigrationLock sync.Mutex // Creates and stores FileInfos for a post created before the FileInfos table existed. func (a *App) MigrateFilenamesToFileInfos(post *model.Post) []*model.FileInfo { if len(post.Filenames) == 0 { - l4g.Warn(utils.T("api.file.migrate_filenames_to_file_infos.no_filenames.warn"), post.Id) + mlog.Warn(fmt.Sprintf("Unable to migrate post to use FileInfos with an empty Filenames field, post_id=%v", post.Id), mlog.String("post_id", post.Id)) return []*model.FileInfo{} } @@ -184,7 +184,7 @@ func (a *App) MigrateFilenamesToFileInfos(post *model.Post) []*model.FileInfo { var channel *model.Channel if result := <-cchan; result.Err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.channel.app_error"), post.Id, post.ChannelId, result.Err) + mlog.Error(fmt.Sprintf("Unable to get channel when migrating post to use FileInfos, post_id=%v, channel_id=%v, err=%v", post.Id, post.ChannelId, result.Err), mlog.String("post_id", post.Id)) return []*model.FileInfo{} } else { channel = result.Data.(*model.Channel) @@ -202,7 +202,7 @@ func (a *App) MigrateFilenamesToFileInfos(post *model.Post) []*model.FileInfo { // Create FileInfo objects for this post infos := make([]*model.FileInfo, 0, len(filenames)) if teamId == "" { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.team_id.error"), post.Id, filenames) + mlog.Error(fmt.Sprint("api.file.migrate_filenames_to_file_infos.team_id.error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, filenames), mlog.String("post_id", post.Id)) } else { for _, filename := range filenames { info := a.GetInfoForFilename(post, teamId, filename) @@ -219,26 +219,26 @@ func (a *App) MigrateFilenamesToFileInfos(post *model.Post) []*model.FileInfo { defer fileMigrationLock.Unlock() if result := <-a.Srv.Store.Post().Get(post.Id); result.Err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.get_post_again.app_error"), post.Id, result.Err) + mlog.Error(fmt.Sprint("api.file.migrate_filenames_to_file_infos.get_post_again.app_error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, result.Err), mlog.String("post_id", post.Id)) return []*model.FileInfo{} } else if newPost := result.Data.(*model.PostList).Posts[post.Id]; len(newPost.Filenames) != len(post.Filenames) { // Another thread has already created FileInfos for this post, so just return those if result := <-a.Srv.Store.FileInfo().GetForPost(post.Id, true, false); result.Err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.get_post_file_infos_again.app_error"), post.Id, result.Err) + mlog.Error(fmt.Sprint("api.file.migrate_filenames_to_file_infos.get_post_file_infos_again.app_error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, result.Err), mlog.String("post_id", post.Id)) return []*model.FileInfo{} } else { - l4g.Debug(utils.T("api.file.migrate_filenames_to_file_infos.not_migrating_post.debug"), post.Id) + mlog.Debug(fmt.Sprintf("Post already migrated to use FileInfos, post_id=%v", post.Id), mlog.String("post_id", post.Id)) return result.Data.([]*model.FileInfo) } } - l4g.Debug(utils.T("api.file.migrate_filenames_to_file_infos.migrating_post.debug"), post.Id) + mlog.Debug(fmt.Sprintf("Migrating post to use FileInfos, post_id=%v", post.Id), mlog.String("post_id", post.Id)) savedInfos := make([]*model.FileInfo, 0, len(infos)) fileIds := make([]string, 0, len(filenames)) for _, info := range infos { if result := <-a.Srv.Store.FileInfo().Save(info); result.Err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.save_file_info.app_error"), post.Id, info.Id, info.Path, result.Err) + mlog.Error(fmt.Sprint("api.file.migrate_filenames_to_file_infos.save_file_info.app_error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, info.Id, info.Path, result.Err), mlog.String("post_id", post.Id)) continue } @@ -255,7 +255,7 @@ func (a *App) MigrateFilenamesToFileInfos(post *model.Post) []*model.FileInfo { // Update Posts to clear Filenames and set FileIds if result := <-a.Srv.Store.Post().Update(newPost, post); result.Err != nil { - l4g.Error(utils.T("api.file.migrate_filenames_to_file_infos.save_post.app_error"), post.Id, newPost.FileIds, post.Filenames, result.Err) + mlog.Error(fmt.Sprint("api.file.migrate_filenames_to_file_infos.save_post.app_error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, newPost.FileIds, post.Filenames, result.Err), mlog.String("post_id", post.Id)) return []*model.FileInfo{} } else { return savedInfos @@ -415,7 +415,7 @@ func prepareImage(fileData []byte) (*image.Image, int, int) { // Decode image bytes into Image object img, imgType, err := image.Decode(bytes.NewReader(fileData)) if err != nil { - l4g.Error(utils.T("api.file.handle_images_forget.decode.error"), err) + mlog.Error(fmt.Sprintf("Unable to decode image err=%v", err)) return nil, 0, 0 } @@ -492,12 +492,12 @@ func (a *App) generateThumbnailImage(img image.Image, thumbnailPath string, widt buf := new(bytes.Buffer) if err := jpeg.Encode(buf, thumbnail, &jpeg.Options{Quality: 90}); err != nil { - l4g.Error(utils.T("api.file.handle_images_forget.encode_jpeg.error"), thumbnailPath, err) + mlog.Error(fmt.Sprintf("Unable to encode image as jpeg path=%v err=%v", thumbnailPath, err)) return } if err := a.WriteFile(buf.Bytes(), thumbnailPath); err != nil { - l4g.Error(utils.T("api.file.handle_images_forget.upload_thumb.error"), thumbnailPath, err) + mlog.Error(fmt.Sprintf("Unable to upload thumbnail path=%v err=%v", thumbnailPath, err)) return } } @@ -514,12 +514,12 @@ func (a *App) generatePreviewImage(img image.Image, previewPath string, width in buf := new(bytes.Buffer) if err := jpeg.Encode(buf, preview, &jpeg.Options{Quality: 90}); err != nil { - l4g.Error(utils.T("api.file.handle_images_forget.encode_preview.error"), previewPath, err) + mlog.Error(fmt.Sprintf("Unable to encode image as preview jpg path=%v err=%v", previewPath, err)) return } if err := a.WriteFile(buf.Bytes(), previewPath); err != nil { - l4g.Error(utils.T("api.file.handle_images_forget.upload_preview.error"), previewPath, err) + mlog.Error(fmt.Sprintf("Unable to upload preview path=%v err=%v", previewPath, err)) return } } diff --git a/app/import.go b/app/import.go index 23a315be7..fc0bfafa6 100644 --- a/app/import.go +++ b/app/import.go @@ -7,6 +7,7 @@ import ( "bufio" "bytes" "encoding/json" + "fmt" "io" "net/http" "os" @@ -16,11 +17,9 @@ import ( "time" "unicode/utf8" - l4g "github.com/alecthomas/log4go" - + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" - "github.com/mattermost/mattermost-server/utils" ) // Import Data Models @@ -715,10 +714,10 @@ func (a *App) ImportUser(data *UserImportData, dryRun bool) *model.AppError { if data.ProfileImage != nil { file, err := os.Open(*data.ProfileImage) if err != nil { - l4g.Error(utils.T("api.import.import_user.profile_image.error"), err) + mlog.Error(fmt.Sprint("api.import.import_user.profile_image.error FIXME: NOT FOUND IN TRANSLATIONS FILE", err)) } if err := a.SetProfileImageFromFile(savedUser.Id, file); err != nil { - l4g.Error(utils.T("api.import.import_user.profile_image.error"), err) + mlog.Error(fmt.Sprint("api.import.import_user.profile_image.error FIXME: NOT FOUND IN TRANSLATIONS FILE", err)) } } @@ -1654,12 +1653,12 @@ func (a *App) OldImportPost(post *model.Post) { post.Hashtags, _ = model.ParseHashtags(post.Message) if result := <-a.Srv.Store.Post().Save(post); result.Err != nil { - l4g.Debug(utils.T("api.import.import_post.saving.debug"), post.UserId, post.Message) + mlog.Debug(fmt.Sprintf("Error saving post. user=%v, message=%v", post.UserId, post.Message)) } for _, fileId := range post.FileIds { if result := <-a.Srv.Store.FileInfo().AttachToPost(fileId, post.Id); result.Err != nil { - l4g.Error(utils.T("api.import.import_post.attach_files.error"), post.Id, post.FileIds, result.Err) + mlog.Error(fmt.Sprintf("Error attaching files to post. postId=%v, fileIds=%v, message=%v", post.Id, post.FileIds, result.Err), mlog.String("post_id", post.Id)) } } @@ -1675,17 +1674,17 @@ func (a *App) OldImportUser(team *model.Team, user *model.User) *model.User { user.Roles = model.SYSTEM_USER_ROLE_ID if result := <-a.Srv.Store.User().Save(user); result.Err != nil { - l4g.Error(utils.T("api.import.import_user.saving.error"), result.Err) + mlog.Error(fmt.Sprintf("Error saving user. err=%v", result.Err)) return nil } else { ruser := result.Data.(*model.User) if cresult := <-a.Srv.Store.User().VerifyEmail(ruser.Id); cresult.Err != nil { - l4g.Error(utils.T("api.import.import_user.set_email.error"), cresult.Err) + mlog.Error(fmt.Sprintf("Failed to set email verified err=%v", cresult.Err)) } if err := a.JoinUserToTeam(team, user, ""); err != nil { - l4g.Error(utils.T("api.import.import_user.join_team.error"), err) + mlog.Error(fmt.Sprintf("Failed to join team when importing err=%v", err)) } return ruser diff --git a/app/ldap.go b/app/ldap.go index ff7a5ed21..22c3b746b 100644 --- a/app/ldap.go +++ b/app/ldap.go @@ -4,9 +4,10 @@ package app import ( + "fmt" "net/http" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -18,7 +19,7 @@ func (a *App) SyncLdap() { if ldapI := a.Ldap; ldapI != nil { ldapI.StartSynchronizeJob(false) } else { - l4g.Error("%v", model.NewAppError("SyncLdap", "ent.ldap.disabled.app_error", nil, "", http.StatusNotImplemented).Error()) + mlog.Error(fmt.Sprintf("%v", model.NewAppError("SyncLdap", "ent.ldap.disabled.app_error", nil, "", http.StatusNotImplemented).Error())) } } }) @@ -68,7 +69,7 @@ func (a *App) SwitchEmailToLdap(email, password, code, ldapId, ldapPassword stri a.Go(func() { if err := a.SendSignInChangeEmail(user.Email, "AD/LDAP", user.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) @@ -114,7 +115,7 @@ func (a *App) SwitchLdapToEmail(ldapPassword, code, email, newPassword string) ( a.Go(func() { if err := a.SendSignInChangeEmail(user.Email, T("api.templates.signin_change_email.body.method_email"), user.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) diff --git a/app/license.go b/app/license.go index 148b10317..310a61fdb 100644 --- a/app/license.go +++ b/app/license.go @@ -9,8 +9,7 @@ import ( "net/http" "strings" - l4g "github.com/alecthomas/log4go" - + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -30,7 +29,7 @@ func (a *App) LoadLicense() { if license != nil { if _, err := a.SaveLicense(licenseBytes); err != nil { - l4g.Info("Failed to save license key loaded from disk err=%v", err.Error()) + mlog.Info(fmt.Sprintf("Failed to save license key loaded from disk err=%v", err.Error())) } else { licenseId = license.Id } @@ -40,9 +39,9 @@ func (a *App) LoadLicense() { if result := <-a.Srv.Store.License().Get(licenseId); result.Err == nil { record := result.Data.(*model.LicenseRecord) a.ValidateAndSetLicenseBytes([]byte(record.Bytes)) - l4g.Info("License key valid unlocking enterprise features.") + mlog.Info("License key valid unlocking enterprise features.") } else { - l4g.Info(utils.T("mattermost.load_license.find.warn")) + mlog.Info("License key from https://mattermost.com required to unlock enterprise features.") } } @@ -140,7 +139,7 @@ func (a *App) ValidateAndSetLicenseBytes(b []byte) { return } - l4g.Warn(utils.T("utils.license.load_license.invalid.warn")) + mlog.Warn("No valid enterprise license found") } func (a *App) SetClientLicense(m map[string]string) { diff --git a/app/notification.go b/app/notification.go index d1f6225b3..7198de764 100644 --- a/app/notification.go +++ b/app/notification.go @@ -15,7 +15,7 @@ import ( "time" "unicode" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -193,14 +193,14 @@ func (a *App) SendNotifications(post *model.Post, team *model.Team, channel *mod // Remove the user as recipient when the user has muted the channel. if channelMuted, ok := channelMemberNotifyPropsMap[id][model.MARK_UNREAD_NOTIFY_PROP]; ok { if channelMuted == model.CHANNEL_MARK_UNREAD_MENTION { - l4g.Debug("Channel muted for user_id %v, channel_mute %v", id, channelMuted) + mlog.Debug(fmt.Sprintf("Channel muted for user_id %v, channel_mute %v", id, channelMuted)) userAllowsEmails = false } } //If email verification is required and user email is not verified don't send email. if a.Config().EmailSettings.RequireEmailVerification && !profileMap[id].EmailVerified { - l4g.Error("Skipped sending notification email to %v, address not verified. [details: user_id=%v]", profileMap[id].Email, id) + mlog.Error(fmt.Sprintf("Skipped sending notification email to %v, address not verified. [details: user_id=%v]", profileMap[id].Email, id)) continue } @@ -266,7 +266,7 @@ func (a *App) SendNotifications(post *model.Post, team *model.Team, channel *mod // MUST be completed before push notifications send for _, uchan := range updateMentionChans { if result := <-uchan; result.Err != nil { - l4g.Warn(utils.T("api.post.update_mention_count_and_forget.update_error"), post.Id, post.ChannelId, result.Err) + mlog.Warn(fmt.Sprintf("Failed to update mention count, post_id=%v channel_id=%v err=%v", post.Id, post.ChannelId, result.Err), mlog.String("post_id", post.Id)) } } @@ -274,7 +274,7 @@ func (a *App) SendNotifications(post *model.Post, team *model.Team, channel *mod if *a.Config().EmailSettings.SendPushNotifications { pushServer := *a.Config().EmailSettings.PushNotificationServer if license := a.License(); pushServer == model.MHPNS && (license == nil || !*license.Features.MHPNS) { - l4g.Warn(utils.T("api.post.send_notifications_and_forget.push_notification.mhpnsWarn")) + mlog.Warn("api.post.send_notifications_and_forget.push_notification.mhpnsWarn FIXME: NOT FOUND IN TRANSLATIONS FILE") sendPushNotifications = false } else { sendPushNotifications = true @@ -330,7 +330,7 @@ func (a *App) SendNotifications(post *model.Post, team *model.Team, channel *mod var infos []*model.FileInfo if result := <-fchan; result.Err != nil { - l4g.Warn(utils.T("api.post.send_notifications.files.error"), post.Id, result.Err) + mlog.Warn(fmt.Sprint("api.post.send_notifications.files.error FIXME: NOT FOUND IN TRANSLATIONS FILE", post.Id, result.Err), mlog.String("post_id", post.Id)) } else { infos = result.Data.([]*model.FileInfo) } @@ -415,7 +415,7 @@ func (a *App) sendNotificationEmail(post *model.Post, user *model.User, channel a.Go(func() { if err := a.SendMail(user.Email, html.UnescapeString(subjectText), bodyText); err != nil { - l4g.Error(utils.T("api.post.send_notifications_and_forget.send.error"), user.Email, err) + mlog.Error(fmt.Sprint("api.post.send_notifications_and_forget.send.error FIXME: NOT FOUND IN TRANSLATIONS FILE", user.Email, err)) } }) @@ -577,7 +577,7 @@ func (a *App) GetMessageForNotification(post *model.Post, translateFunc i18n.Tra // extract the filenames from their paths and determine what type of files are attached var infos []*model.FileInfo if result := <-a.Srv.Store.FileInfo().GetForPost(post.Id, true, true); result.Err != nil { - l4g.Warn(utils.T("api.post.get_message_for_notification.get_files.error"), post.Id, result.Err) + mlog.Warn(fmt.Sprintf("Encountered error when getting files for notification message, post_id=%v, err=%v", post.Id, result.Err), mlog.String("post_id", post.Id)) } else { infos = result.Data.([]*model.FileInfo) } @@ -617,7 +617,7 @@ func (a *App) sendPushNotification(post *model.Post, user *model.User, channel * msg := model.PushNotification{} if badge := <-a.Srv.Store.User().GetUnreadCount(user.Id); badge.Err != nil { msg.Badge = 1 - l4g.Error(utils.T("store.sql_user.get_unread_count.app_error"), user.Id, badge.Err) + mlog.Error(fmt.Sprint("We could not get the unread message count for the user", user.Id, badge.Err), mlog.String("user_id", user.Id)) } else { msg.Badge = int(badge.Data.(int64)) } @@ -651,7 +651,7 @@ func (a *App) sendPushNotification(post *model.Post, user *model.User, channel * tmpMessage := *model.PushNotificationFromJson(strings.NewReader(msg.ToJson())) tmpMessage.SetDeviceIdAndPlatform(session.DeviceId) - l4g.Debug("Sending push notification to device %v for user %v with msg of '%v'", tmpMessage.DeviceId, user.Id, msg.Message) + mlog.Debug(fmt.Sprintf("Sending push notification to device %v for user %v with msg of '%v'", tmpMessage.DeviceId, user.Id, msg.Message), mlog.String("user_id", user.Id)) a.Go(func(session *model.Session) func() { return func() { @@ -729,7 +729,7 @@ func (a *App) ClearPushNotification(userId string, channelId string) { sessions, err := a.getMobileAppSessions(userId) if err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) return } @@ -739,12 +739,12 @@ func (a *App) ClearPushNotification(userId string, channelId string) { msg.ContentAvailable = 0 if badge := <-a.Srv.Store.User().GetUnreadCount(userId); badge.Err != nil { msg.Badge = 0 - l4g.Error(utils.T("store.sql_user.get_unread_count.app_error"), userId, badge.Err) + mlog.Error(fmt.Sprint("We could not get the unread message count for the user", userId, badge.Err), mlog.String("user_id", userId)) } else { msg.Badge = int(badge.Data.(int64)) } - l4g.Debug(utils.T("api.post.send_notifications_and_forget.clear_push_notification.debug"), msg.DeviceId, msg.ChannelId) + mlog.Debug(fmt.Sprintf("Clearing push notification to %v with channel_id %v", msg.DeviceId, msg.ChannelId)) for _, session := range sessions { tmpMessage := *model.PushNotificationFromJson(strings.NewReader(msg.ToJson())) @@ -762,7 +762,7 @@ func (a *App) sendToPushProxy(msg model.PushNotification, session *model.Session request, _ := http.NewRequest("POST", strings.TrimRight(*a.Config().EmailSettings.PushNotificationServer, "/")+model.API_URL_SUFFIX_V1+"/send_push", strings.NewReader(msg.ToJson())) if resp, err := a.HTTPClient(true).Do(request); err != nil { - l4g.Error("Device push reported as error for UserId=%v SessionId=%v message=%v", session.UserId, session.Id, err.Error()) + mlog.Error(fmt.Sprintf("Device push reported as error for UserId=%v SessionId=%v message=%v", session.UserId, session.Id, err.Error()), mlog.String("user_id", session.UserId)) } else { pushResponse := model.PushResponseFromJson(resp.Body) if resp.Body != nil { @@ -770,13 +770,13 @@ func (a *App) sendToPushProxy(msg model.PushNotification, session *model.Session } if pushResponse[model.PUSH_STATUS] == model.PUSH_STATUS_REMOVE { - l4g.Info("Device was reported as removed for UserId=%v SessionId=%v removing push for this session", session.UserId, session.Id) + mlog.Info(fmt.Sprintf("Device was reported as removed for UserId=%v SessionId=%v removing push for this session", session.UserId, session.Id), mlog.String("user_id", session.UserId)) a.AttachDeviceId(session.Id, "", session.ExpiresAt) a.ClearSessionCacheForUser(session.UserId) } if pushResponse[model.PUSH_STATUS] == model.PUSH_STATUS_FAIL { - l4g.Error("Device push reported as error for UserId=%v SessionId=%v message=%v", session.UserId, session.Id, pushResponse[model.PUSH_STATUS_ERROR_MSG]) + mlog.Error(fmt.Sprintf("Device push reported as error for UserId=%v SessionId=%v message=%v", session.UserId, session.Id, pushResponse[model.PUSH_STATUS_ERROR_MSG]), mlog.String("user_id", session.UserId)) } } } diff --git a/app/oauth.go b/app/oauth.go index 630fd3e2d..13fbd5a73 100644 --- a/app/oauth.go +++ b/app/oauth.go @@ -6,14 +6,15 @@ package app import ( "bytes" b64 "encoding/base64" + "fmt" "io" "net/http" "net/url" "strings" "time" - l4g "github.com/alecthomas/log4go" "github.com/mattermost/mattermost-server/einterfaces" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -226,7 +227,7 @@ func (a *App) GetOAuthAccessToken(clientId, grantType, redirectUri, code, secret accessData = &model.AccessData{ClientId: clientId, UserId: user.Id, Token: session.Token, RefreshToken: model.NewId(), RedirectUri: redirectUri, ExpiresAt: session.ExpiresAt, Scope: authData.Scope} if result := <-a.Srv.Store.OAuth().SaveAccessData(accessData); result.Err != nil { - l4g.Error(result.Err) + mlog.Error(fmt.Sprint(result.Err)) return nil, model.NewAppError("GetOAuthAccessToken", "api.oauth.get_access_token.internal_saving.app_error", nil, "", http.StatusInternalServerError) } @@ -295,7 +296,7 @@ func (a *App) newSessionUpdateToken(appName string, accessData *model.AccessData accessData.RefreshToken = model.NewId() accessData.ExpiresAt = session.ExpiresAt if result := <-a.Srv.Store.OAuth().UpdateAccessData(accessData); result.Err != nil { - l4g.Error(result.Err) + mlog.Error(fmt.Sprint(result.Err)) return nil, model.NewAppError("newSessionUpdateToken", "web.get_access_token.internal_saving.app_error", nil, "", http.StatusInternalServerError) } accessRsp := &model.AccessResponse{ @@ -528,7 +529,7 @@ func (a *App) CompleteSwitchWithOAuth(service string, userData io.ReadCloser, em a.Go(func() { if err := a.SendSignInChangeEmail(user.Email, strings.Title(service)+" SSO", user.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) @@ -774,7 +775,7 @@ func (a *App) SwitchOAuthToEmail(email, password, requesterId string) (string, * a.Go(func() { if err := a.SendSignInChangeEmail(user.Email, T("api.templates.signin_change_email.body.method_email"), user.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) diff --git a/app/plugin.go b/app/plugin.go index 903f4b767..3da9cea40 100644 --- a/app/plugin.go +++ b/app/plugin.go @@ -17,9 +17,8 @@ import ( "strings" "unicode/utf8" - l4g "github.com/alecthomas/log4go" - "github.com/gorilla/mux" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" @@ -48,7 +47,7 @@ func (a *App) initBuiltInPlugins() { "ldapextras": &ldapextras.Plugin{}, } for id, p := range plugins { - l4g.Debug("Initializing built-in plugin: " + id) + mlog.Debug("Initializing built-in plugin: " + id) api := &BuiltInPluginAPI{ id: id, router: a.Srv.Router.PathPrefix("/plugins/" + id).Subrouter(), @@ -70,13 +69,13 @@ func (a *App) initBuiltInPlugins() { // and deactivate all other plugins. func (a *App) ActivatePlugins() { if a.PluginEnv == nil { - l4g.Error("plugin env not initialized") + mlog.Error("plugin env not initialized") return } plugins, err := a.PluginEnv.Plugins() if err != nil { - l4g.Error("failed to activate plugins: " + err.Error()) + mlog.Error("failed to activate plugins: " + err.Error()) return } @@ -92,13 +91,13 @@ func (a *App) ActivatePlugins() { if pluginState.Enable && !active { if err := a.activatePlugin(plugin.Manifest); err != nil { - l4g.Error("%v plugin enabled in config.json but failing to activate err=%v", plugin.Manifest.Id, err.DetailedError) + mlog.Error(fmt.Sprintf("%v plugin enabled in config.json but failing to activate err=%v", plugin.Manifest.Id, err.DetailedError)) continue } } else if !pluginState.Enable && active { if err := a.deactivatePlugin(plugin.Manifest); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } } @@ -115,7 +114,7 @@ func (a *App) activatePlugin(manifest *model.Manifest) *model.AppError { a.Publish(message) } - l4g.Info("Activated %v plugin", manifest.Id) + mlog.Info(fmt.Sprintf("Activated %v plugin", manifest.Id)) return nil } @@ -132,7 +131,7 @@ func (a *App) deactivatePlugin(manifest *model.Manifest) *model.AppError { a.Publish(message) } - l4g.Info("Deactivated %v plugin", manifest.Id) + mlog.Info(fmt.Sprintf("Deactivated %v plugin", manifest.Id)) return nil } @@ -370,15 +369,15 @@ func (a *App) InitPlugins(pluginPath, webappPath string, supervisorOverride plug return } - l4g.Info("Starting up plugins") + mlog.Info("Starting up plugins") if err := os.Mkdir(pluginPath, 0744); err != nil && !os.IsExist(err) { - l4g.Error("failed to start up plugins: " + err.Error()) + mlog.Error("failed to start up plugins: " + err.Error()) return } if err := os.Mkdir(webappPath, 0744); err != nil && !os.IsExist(err) { - l4g.Error("failed to start up plugins: " + err.Error()) + mlog.Error("failed to start up plugins: " + err.Error()) return } @@ -400,15 +399,15 @@ func (a *App) InitPlugins(pluginPath, webappPath string, supervisorOverride plug if supervisorOverride != nil { options = append(options, pluginenv.SupervisorProvider(supervisorOverride)) } else if err := sandbox.CheckSupport(); err != nil { - l4g.Warn(err.Error()) - l4g.Warn("plugin sandboxing is not supported. plugins will run with the same access level as the server. See documentation to learn more: https://developers.mattermost.com/extend/plugins/security/") + mlog.Warn(err.Error()) + mlog.Warn("plugin sandboxing is not supported. plugins will run with the same access level as the server. See documentation to learn more: https://developers.mattermost.com/extend/plugins/security/") options = append(options, pluginenv.SupervisorProvider(rpcplugin.SupervisorProvider)) } else { options = append(options, pluginenv.SupervisorProvider(sandbox.SupervisorProvider)) } if env, err := pluginenv.New(options...); err != nil { - l4g.Error("failed to start up plugins: " + err.Error()) + mlog.Error("failed to start up plugins: " + err.Error()) return } else { a.PluginEnv = env @@ -416,15 +415,15 @@ func (a *App) InitPlugins(pluginPath, webappPath string, supervisorOverride plug for id, asset := range prepackagedPlugins { if tarball, err := asset("plugin.tar.gz"); err != nil { - l4g.Error("failed to install prepackaged plugin: " + err.Error()) + mlog.Error("failed to install prepackaged plugin: " + err.Error()) } else if tarball != nil { a.removePlugin(id, true) if _, err := a.installPlugin(bytes.NewReader(tarball), true); err != nil { - l4g.Error("failed to install prepackaged plugin: " + err.Error()) + mlog.Error("failed to install prepackaged plugin: " + err.Error()) } if _, ok := a.Config().PluginSettings.PluginStates[id]; !ok && id != "zoom" { if err := a.EnablePlugin(id); err != nil { - l4g.Error("failed to enable prepackaged plugin: " + err.Error()) + mlog.Error("failed to enable prepackaged plugin: " + err.Error()) } } } @@ -441,7 +440,7 @@ func (a *App) InitPlugins(pluginPath, webappPath string, supervisorOverride plug } for _, err := range a.PluginEnv.Hooks().OnConfigurationChange() { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) @@ -451,7 +450,7 @@ func (a *App) InitPlugins(pluginPath, webappPath string, supervisorOverride plug func (a *App) ServePluginRequest(w http.ResponseWriter, r *http.Request) { if a.PluginEnv == nil || !*a.Config().PluginSettings.Enable { err := model.NewAppError("ServePluginRequest", "app.plugin.disabled.app_error", nil, "Enable plugins to serve plugin requests", http.StatusNotImplemented) - l4g.Error(err.Error()) + mlog.Error(err.Error()) w.WriteHeader(err.StatusCode) w.Header().Set("Content-Type", "application/json") w.Write([]byte(err.ToJson())) @@ -507,10 +506,10 @@ func (a *App) ShutDownPlugins() { return } - l4g.Info("Shutting down plugins") + mlog.Info("Shutting down plugins") for _, err := range a.PluginEnv.Shutdown() { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } a.RemoveConfigListener(a.PluginConfigListenerId) a.PluginConfigListenerId = "" @@ -533,7 +532,7 @@ func (a *App) SetPluginKey(pluginId string, key string, value []byte) *model.App result := <-a.Srv.Store.Plugin().SaveOrUpdate(kv) if result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) } return result.Err @@ -546,7 +545,7 @@ func (a *App) GetPluginKey(pluginId string, key string) ([]byte, *model.AppError if result.Err.StatusCode == http.StatusNotFound { return nil, nil } - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) return nil, result.Err } @@ -559,7 +558,7 @@ func (a *App) DeletePluginKey(pluginId string, key string) *model.AppError { result := <-a.Srv.Store.Plugin().Delete(pluginId, getKeyHash(key)) if result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) } return result.Err diff --git a/app/plugin/ldapextras/plugin.go b/app/plugin/ldapextras/plugin.go index 3af55c2ac..e0645b68e 100644 --- a/app/plugin/ldapextras/plugin.go +++ b/app/plugin/ldapextras/plugin.go @@ -8,10 +8,10 @@ import ( "net/http" "sync/atomic" - l4g "github.com/alecthomas/log4go" "github.com/gorilla/mux" "github.com/mattermost/mattermost-server/app/plugin" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" ) @@ -34,7 +34,7 @@ func (p *Plugin) config() *Configuration { func (p *Plugin) OnConfigurationChange() { var configuration Configuration if err := p.api.LoadPluginConfiguration(&configuration); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } p.configuration.Store(&configuration) } diff --git a/app/post.go b/app/post.go index 4ce009369..41139da63 100644 --- a/app/post.go +++ b/app/post.go @@ -14,8 +14,8 @@ import ( "regexp" "strings" - l4g "github.com/alecthomas/log4go" "github.com/dyatlov/go-opengraph/opengraph" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -78,7 +78,7 @@ func (a *App) CreatePostAsUser(post *model.Post) (*model.Post, *model.AppError) // Update the LastViewAt only if the post does not have from_webhook prop set (eg. Zapier app) if _, ok := post.Props["from_webhook"]; !ok { if result := <-a.Srv.Store.Channel().UpdateLastViewedAt([]string{post.ChannelId}, post.UserId); result.Err != nil { - l4g.Error(utils.T("api.post.create_post.last_viewed.error"), post.ChannelId, post.UserId, result.Err) + mlog.Error(fmt.Sprintf("Encountered error updating last viewed, channel_id=%s, user_id=%s, err=%v", post.ChannelId, post.UserId, result.Err)) } if *a.Config().ServiceSettings.EnableChannelViewedMessages { @@ -182,7 +182,7 @@ func (a *App) CreatePost(post *model.Post, channel *model.Channel, triggerWebhoo for _, fileId := range post.FileIds { if result := <-a.Srv.Store.FileInfo().AttachToPost(fileId, post.Id); result.Err != nil { - l4g.Error(utils.T("api.post.create_post.attach_files.error"), post.Id, post.FileIds, post.UserId, result.Err) + mlog.Error(fmt.Sprintf("Encountered error attaching files to post, post_id=%s, user_id=%s, file_ids=%v, err=%v", post.Id, post.FileIds, post.UserId, result.Err), mlog.String("post_id", post.Id)) } } @@ -266,7 +266,7 @@ func (a *App) handlePostEvents(post *model.Post, user *model.User, channel *mode if triggerWebhooks { a.Go(func() { if err := a.handleWebhookEvents(post, team, channel, user); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) } @@ -378,7 +378,7 @@ func (a *App) UpdatePost(post *model.Post, safeUpdate bool) (*model.Post, *model if esInterface != nil && *a.Config().ElasticsearchSettings.EnableIndexing { a.Go(func() { if rchannel := <-a.Srv.Store.Channel().GetForPost(rpost.Id); rchannel.Err != nil { - l4g.Error("Couldn't get channel %v for post %v for Elasticsearch indexing.", rpost.ChannelId, rpost.Id) + mlog.Error(fmt.Sprintf("Couldn't get channel %v for post %v for Elasticsearch indexing.", rpost.ChannelId, rpost.Id)) } else { esInterface.IndexPost(rpost, rchannel.Data.(*model.Channel).TeamId) } @@ -576,7 +576,7 @@ func (a *App) DeletePost(postId string) (*model.Post, *model.AppError) { func (a *App) DeleteFlaggedPosts(postId string) { if result := <-a.Srv.Store.Preference().DeleteCategoryAndName(model.PREFERENCE_CATEGORY_FLAGGED_POST, postId); result.Err != nil { - l4g.Warn(utils.T("api.post.delete_flagged_post.app_error.warn"), result.Err) + mlog.Warn(fmt.Sprintf("Unable to delete flagged post preference when deleting post, err=%v", result.Err)) return } } @@ -587,7 +587,7 @@ func (a *App) DeletePostFiles(post *model.Post) { } if result := <-a.Srv.Store.FileInfo().DeleteForPost(post.Id); result.Err != nil { - l4g.Warn(utils.T("api.post.delete_post_files.app_error.warn"), post.Id, result.Err) + mlog.Warn(fmt.Sprintf("Encountered error when deleting files for post, post_id=%v, err=%v", post.Id, result.Err), mlog.String("post_id", post.Id)) } } @@ -605,7 +605,7 @@ func (a *App) SearchPostsInTeam(terms string, userId string, teamId string, isOr // Convert channel names to channel IDs for idx, channelName := range params.InChannels { if channel, err := a.GetChannelByName(channelName, teamId); err != nil { - l4g.Error(err) + mlog.Error(fmt.Sprint(err)) } else { params.InChannels[idx] = channel.Id } @@ -614,7 +614,7 @@ func (a *App) SearchPostsInTeam(terms string, userId string, teamId string, isOr // Convert usernames to user IDs for idx, username := range params.FromUsers { if user, err := a.GetUserByUsername(username); err != nil { - l4g.Error(err) + mlog.Error(fmt.Sprint(err)) } else { params.FromUsers[idx] = user.Id } @@ -632,7 +632,7 @@ func (a *App) SearchPostsInTeam(terms string, userId string, teamId string, isOr // We only allow the user to search in channels they are a member of. userChannels, err := a.GetChannelsForUser(teamId, userId) if err != nil { - l4g.Error(err) + mlog.Error(fmt.Sprint(err)) return nil, err } @@ -721,13 +721,13 @@ func (a *App) GetOpenGraphMetadata(requestURL string) *opengraph.OpenGraph { res, err := a.HTTPClient(false).Get(requestURL) if err != nil { - l4g.Error("GetOpenGraphMetadata request failed for url=%v with err=%v", requestURL, err.Error()) + mlog.Error(fmt.Sprintf("GetOpenGraphMetadata request failed for url=%v with err=%v", requestURL, err.Error())) return og } defer consumeAndClose(res) if err := og.ProcessHTML(res.Body); err != nil { - l4g.Error("GetOpenGraphMetadata processing failed for url=%v with err=%v", requestURL, err.Error()) + mlog.Error(fmt.Sprintf("GetOpenGraphMetadata processing failed for url=%v with err=%v", requestURL, err.Error())) } makeOpenGraphURLsAbsolute(og, requestURL) @@ -738,7 +738,7 @@ func (a *App) GetOpenGraphMetadata(requestURL string) *opengraph.OpenGraph { func makeOpenGraphURLsAbsolute(og *opengraph.OpenGraph, requestURL string) { parsedRequestURL, err := url.Parse(requestURL) if err != nil { - l4g.Warn("makeOpenGraphURLsAbsolute failed to parse url=%v", requestURL) + mlog.Warn(fmt.Sprintf("makeOpenGraphURLsAbsolute failed to parse url=%v", requestURL)) return } @@ -749,7 +749,7 @@ func makeOpenGraphURLsAbsolute(og *opengraph.OpenGraph, requestURL string) { parsedResultURL, err := url.Parse(resultURL) if err != nil { - l4g.Warn("makeOpenGraphURLsAbsolute failed to parse result url=%v", resultURL) + mlog.Warn(fmt.Sprintf("makeOpenGraphURLsAbsolute failed to parse result url=%v", resultURL)) return resultURL } @@ -962,7 +962,7 @@ func (a *App) ImageProxyRemover() (f func(string) string) { func (a *App) MaxPostSize() int { maxPostSize := model.POST_MESSAGE_MAX_RUNES_V1 if result := <-a.Srv.Store.Post().GetMaxPostSize(); result.Err != nil { - l4g.Error(result.Err) + mlog.Error(fmt.Sprint(result.Err)) } else { maxPostSize = result.Data.(int) } diff --git a/app/ratelimit.go b/app/ratelimit.go index 13508f36f..77d15caa2 100644 --- a/app/ratelimit.go +++ b/app/ratelimit.go @@ -4,12 +4,13 @@ package app import ( + "fmt" "math" "net/http" "strconv" "strings" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" "github.com/pkg/errors" @@ -74,14 +75,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 { - l4g.Critical("Internal server error when rate limiting. Rate Limiting broken. Error:" + err.Error()) + mlog.Critical("Internal server error when rate limiting. Rate Limiting broken. Error:" + err.Error()) return false } setRateLimitHeaders(w, context) if limited { - l4g.Error("Denied due to throttling settings code=429 key=%v", key) + mlog.Error(fmt.Sprintf("Denied due to throttling settings code=429 key=%v", key)) http.Error(w, "limit exceeded", 429) } diff --git a/app/role.go b/app/role.go index c99d8365b..c9278e0bd 100644 --- a/app/role.go +++ b/app/role.go @@ -6,8 +6,9 @@ package app import ( "reflect" - "github.com/mattermost/mattermost-server/model" "net/http" + + "github.com/mattermost/mattermost-server/model" ) func (a *App) GetRole(id string) (*model.Role, *model.AppError) { diff --git a/app/security_update_check.go b/app/security_update_check.go index 1f1759fef..15bb81e5a 100644 --- a/app/security_update_check.go +++ b/app/security_update_check.go @@ -4,13 +4,14 @@ package app import ( + "fmt" "io/ioutil" "net/http" "net/url" "runtime" "strconv" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -38,7 +39,7 @@ func (a *App) DoSecurityUpdateCheck() { currentTime := model.GetMillis() if (currentTime - lastSecurityTime) > SECURITY_UPDATE_PERIOD { - l4g.Debug(utils.T("mattermost.security_checks.debug")) + mlog.Debug("Checking for security update from Mattermost") v := url.Values{} @@ -75,7 +76,7 @@ func (a *App) DoSecurityUpdateCheck() { res, err := http.Get(SECURITY_URL + "/security?" + v.Encode()) if err != nil { - l4g.Error(utils.T("mattermost.security_info.error")) + mlog.Error("Failed to get security update information from Mattermost.") return } @@ -86,26 +87,26 @@ func (a *App) DoSecurityUpdateCheck() { if bulletin.AppliesToVersion == model.CurrentVersion { if props["SecurityBulletin_"+bulletin.Id] == "" { if results := <-a.Srv.Store.User().GetSystemAdminProfiles(); results.Err != nil { - l4g.Error(utils.T("mattermost.system_admins.error")) + mlog.Error("Failed to get system admins for security update information from Mattermost.") return } else { users := results.Data.(map[string]*model.User) resBody, err := http.Get(SECURITY_URL + "/bulletins/" + bulletin.Id) if err != nil { - l4g.Error(utils.T("mattermost.security_bulletin.error")) + mlog.Error("Failed to get security bulletin details") return } body, err := ioutil.ReadAll(resBody.Body) res.Body.Close() if err != nil || resBody.StatusCode != 200 { - l4g.Error(utils.T("mattermost.security_bulletin_read.error")) + mlog.Error("Failed to read security bulletin details") return } for _, user := range users { - l4g.Info(utils.T("mattermost.send_bulletin.info"), bulletin.Id, user.Email) + mlog.Info(fmt.Sprintf("Sending security bulletin for %v to %v", bulletin.Id, user.Email)) a.SendMail(user.Email, utils.T("mattermost.bulletin.subject"), string(body)) } } diff --git a/app/server.go b/app/server.go index e89041ebe..7d229201d 100644 --- a/app/server.go +++ b/app/server.go @@ -15,12 +15,12 @@ import ( "strings" "time" - l4g "github.com/alecthomas/log4go" "github.com/gorilla/handlers" "github.com/gorilla/mux" "github.com/pkg/errors" "golang.org/x/crypto/acme/autocert" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -50,8 +50,8 @@ type RecoveryLogger struct { } func (rl *RecoveryLogger) Println(i ...interface{}) { - l4g.Error("Please check the std error output for the stack trace") - l4g.Error(i) + mlog.Error("Please check the std error output for the stack trace") + mlog.Error(fmt.Sprint(i)) } type CorsWrapper struct { @@ -97,12 +97,12 @@ func redirectHTTPToHTTPS(w http.ResponseWriter, r *http.Request) { } func (a *App) StartServer() error { - l4g.Info(utils.T("api.server.start_server.starting.info")) + mlog.Info("Starting Server...") var handler http.Handler = &CorsWrapper{a.Config, a.Srv.Router} if *a.Config().RateLimitSettings.Enable { - l4g.Info(utils.T("api.server.start_server.rate.info")) + mlog.Info("RateLimiter is enabled") rateLimiter, err := NewRateLimiter(&a.Config().RateLimitSettings) if err != nil { @@ -117,6 +117,7 @@ func (a *App) StartServer() error { Handler: handlers.RecoveryHandler(handlers.RecoveryLogger(&RecoveryLogger{}), handlers.PrintRecoveryStack(true))(handler), ReadTimeout: time.Duration(*a.Config().ServiceSettings.ReadTimeout) * time.Second, WriteTimeout: time.Duration(*a.Config().ServiceSettings.WriteTimeout) * time.Second, + ErrorLog: a.Log.StdLog(mlog.String("source", "httpserver")), } addr := *a.Config().ServiceSettings.ListenAddress @@ -135,7 +136,7 @@ func (a *App) StartServer() error { } a.Srv.ListenAddr = listener.Addr().(*net.TCPAddr) - l4g.Info(utils.T("api.server.start_server.listening.info"), listener.Addr().String()) + mlog.Info(fmt.Sprintf("Server is listening on %v", listener.Addr().String())) // Migration from old let's encrypt library if *a.Config().ServiceSettings.UseLetsEncrypt { @@ -151,24 +152,33 @@ func (a *App) StartServer() error { if *a.Config().ServiceSettings.Forward80To443 { if host, port, err := net.SplitHostPort(addr); err != nil { - l4g.Error("Unable to setup forwarding: " + err.Error()) + mlog.Error("Unable to setup forwarding: " + err.Error()) } else if port != "443" { return fmt.Errorf(utils.T("api.server.start_server.forward80to443.enabled_but_listening_on_wrong_port"), port) } else { httpListenAddress := net.JoinHostPort(host, "http") if *a.Config().ServiceSettings.UseLetsEncrypt { - go http.ListenAndServe(httpListenAddress, m.HTTPHandler(nil)) + server := &http.Server{ + Addr: httpListenAddress, + Handler: m.HTTPHandler(nil), + ErrorLog: a.Log.StdLog(mlog.String("source", "le_forwarder_server")), + } + go server.ListenAndServe() } else { go func() { redirectListener, err := net.Listen("tcp", httpListenAddress) if err != nil { - l4g.Error("Unable to setup forwarding: " + err.Error()) + mlog.Error("Unable to setup forwarding: " + err.Error()) return } defer redirectListener.Close() - http.Serve(redirectListener, http.HandlerFunc(redirectHTTPToHTTPS)) + server := &http.Server{ + Handler: handler, + ErrorLog: a.Log.StdLog(mlog.String("source", "forwarder_server")), + } + server.Serve(redirectListener) }() } } @@ -197,7 +207,7 @@ func (a *App) StartServer() error { err = a.Srv.Server.Serve(listener) } if err != nil && err != http.ErrServerClosed { - l4g.Critical(utils.T("api.server.start_server.starting.critical"), err) + mlog.Critical(fmt.Sprintf("Error starting server, err:%v", err)) time.Sleep(time.Second) } close(a.Srv.didFinishListen) @@ -213,7 +223,7 @@ func (a *App) StopServer() { didShutdown := false for a.Srv.didFinishListen != nil && !didShutdown { if err := a.Srv.Server.Shutdown(ctx); err != nil { - l4g.Warn(err.Error()) + mlog.Warn(err.Error()) } timer := time.NewTimer(time.Millisecond * 50) select { diff --git a/app/session.go b/app/session.go index 03754398d..53170cec0 100644 --- a/app/session.go +++ b/app/session.go @@ -4,12 +4,11 @@ package app import ( + "fmt" "net/http" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" - "github.com/mattermost/mattermost-server/utils" - - l4g "github.com/alecthomas/log4go" ) func (a *App) CreateSession(session *model.Session) (*model.Session, *model.AppError) { @@ -171,10 +170,10 @@ func (a *App) RevokeSessionsForDeviceId(userId string, deviceId string, currentS sessions := result.Data.([]*model.Session) for _, session := range sessions { if session.DeviceId == deviceId && session.Id != currentSessionId { - l4g.Debug(utils.T("api.user.login.revoking.app_error"), session.Id, userId) + mlog.Debug(fmt.Sprintf("Revoking sessionId=%v for userId=%v re-login with same device Id", session.Id, userId), mlog.String("user_id", userId)) if err := a.RevokeSession(session); err != nil { // Soft error so we still remove the other sessions - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } } @@ -233,7 +232,7 @@ func (a *App) UpdateLastActivityAtIfNeeded(session model.Session) { } if result := <-a.Srv.Store.Session().UpdateLastActivityAt(session.Id, now); result.Err != nil { - l4g.Error(utils.T("api.status.last_activity.error"), session.UserId, session.Id, result.Err) + mlog.Error(fmt.Sprintf("Failed to update LastActivityAt for user_id=%v and session_id=%v, err=%v", session.UserId, session.Id, result.Err), mlog.String("user_id", session.UserId)) } session.LastActivityAt = now @@ -256,11 +255,11 @@ func (a *App) CreateUserAccessToken(token *model.UserAccessToken) (*model.UserAc } if result := <-uchan; result.Err != nil { - l4g.Error(result.Err.Error()) + mlog.Error(result.Err.Error()) } else { user := result.Data.(*model.User) if err := a.SendUserAccessTokenAddedEmail(user.Email, user.Locale); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } diff --git a/app/slackimport.go b/app/slackimport.go index d5e7fe2b2..3333af604 100644 --- a/app/slackimport.go +++ b/app/slackimport.go @@ -7,6 +7,7 @@ import ( "archive/zip" "bytes" "encoding/json" + "fmt" "io" "mime/multipart" "path/filepath" @@ -17,7 +18,7 @@ import ( "net/http" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -81,7 +82,7 @@ func SlackConvertTimeStamp(ts string) int64 { timeStamp, err := strconv.ParseInt(timeString, 10, 64) if err != nil { - l4g.Warn(utils.T("api.slackimport.slack_convert_timestamp.bad.warn")) + mlog.Warn("Slack Import: Bad timestamp detected.") return 1 } return timeStamp * 1000 // Convert to milliseconds @@ -105,7 +106,7 @@ func SlackParseChannels(data io.Reader) ([]SlackChannel, error) { var channels []SlackChannel if err := decoder.Decode(&channels); err != nil { - l4g.Warn(utils.T("api.slackimport.slack_parse_channels.error")) + mlog.Warn("Slack Import: Error occurred when parsing some Slack channels. Import may work anyway.") return channels, err } return channels, nil @@ -127,23 +128,23 @@ func SlackParsePosts(data io.Reader) ([]SlackPost, error) { var posts []SlackPost if err := decoder.Decode(&posts); err != nil { - l4g.Warn(utils.T("api.slackimport.slack_parse_posts.error")) + mlog.Warn("Slack Import: Error occurred when parsing some Slack posts. Import may work anyway.") return posts, err } return posts, nil } -func (a *App) SlackAddUsers(teamId string, slackusers []SlackUser, log *bytes.Buffer) map[string]*model.User { +func (a *App) SlackAddUsers(teamId string, slackusers []SlackUser, importerLog *bytes.Buffer) map[string]*model.User { // Log header - log.WriteString(utils.T("api.slackimport.slack_add_users.created")) - log.WriteString("===============\r\n\r\n") + importerLog.WriteString(utils.T("api.slackimport.slack_add_users.created")) + importerLog.WriteString("===============\r\n\r\n") addedUsers := make(map[string]*model.User) // Need the team var team *model.Team if result := <-a.Srv.Store.Team().Get(teamId); result.Err != nil { - log.WriteString(utils.T("api.slackimport.slack_import.team_fail")) + importerLog.WriteString(utils.T("api.slackimport.slack_import.team_fail")) return addedUsers } else { team = result.Data.(*model.Team) @@ -155,8 +156,8 @@ func (a *App) SlackAddUsers(teamId string, slackusers []SlackUser, log *bytes.Bu email := sUser.Profile.Email if email == "" { email = sUser.Username + "@example.com" - log.WriteString(utils.T("api.slackimport.slack_add_users.missing_email_address", map[string]interface{}{"Email": email, "Username": sUser.Username})) - l4g.Warn(utils.T("api.slackimport.slack_add_users.missing_email_address.warn", map[string]interface{}{"Email": email, "Username": sUser.Username})) + importerLog.WriteString(utils.T("api.slackimport.slack_add_users.missing_email_address", map[string]interface{}{"Email": email, "Username": sUser.Username})) + mlog.Warn("Slack Import: User {{.Username}} does not have an email address in the Slack export. Used {{.Email}} as a placeholder. The user should update their email address once logged in to the system.") } password := model.NewId() @@ -166,9 +167,9 @@ func (a *App) SlackAddUsers(teamId string, slackusers []SlackUser, log *bytes.Bu existingUser := result.Data.(*model.User) addedUsers[sUser.Id] = existingUser if err := a.JoinUserToTeam(team, addedUsers[sUser.Id], ""); err != nil { - log.WriteString(utils.T("api.slackimport.slack_add_users.merge_existing_failed", map[string]interface{}{"Email": existingUser.Email, "Username": existingUser.Username})) + importerLog.WriteString(utils.T("api.slackimport.slack_add_users.merge_existing_failed", map[string]interface{}{"Email": existingUser.Email, "Username": existingUser.Username})) } else { - log.WriteString(utils.T("api.slackimport.slack_add_users.merge_existing", map[string]interface{}{"Email": existingUser.Email, "Username": existingUser.Username})) + importerLog.WriteString(utils.T("api.slackimport.slack_add_users.merge_existing", map[string]interface{}{"Email": existingUser.Email, "Username": existingUser.Username})) } continue } @@ -183,9 +184,9 @@ func (a *App) SlackAddUsers(teamId string, slackusers []SlackUser, log *bytes.Bu if mUser := a.OldImportUser(team, &newUser); mUser != nil { addedUsers[sUser.Id] = mUser - log.WriteString(utils.T("api.slackimport.slack_add_users.email_pwd", map[string]interface{}{"Email": newUser.Email, "Password": password})) + importerLog.WriteString(utils.T("api.slackimport.slack_add_users.email_pwd", map[string]interface{}{"Email": newUser.Email, "Password": password})) } else { - log.WriteString(utils.T("api.slackimport.slack_add_users.unable_import", map[string]interface{}{"Username": sUser.Username})) + importerLog.WriteString(utils.T("api.slackimport.slack_add_users.unable_import", map[string]interface{}{"Username": sUser.Username})) } } @@ -227,10 +228,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack switch { case sPost.Type == "message" && (sPost.SubType == "" || sPost.SubType == "file_share"): if sPost.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.without_user.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } newPost := model.Post{ @@ -248,19 +249,19 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportPost(&newPost) for _, fileId := range newPost.FileIds { if result := <-a.Srv.Store.FileInfo().AttachToPost(fileId, newPost.Id); result.Err != nil { - l4g.Error(utils.T("api.slackimport.slack_add_posts.attach_files.error"), newPost.Id, newPost.FileIds, result.Err) + mlog.Error(fmt.Sprintf("Slack Import: An error occurred when attaching files to a message, post_id=%s, file_ids=%v, err=%v.", newPost.Id, newPost.FileIds, result.Err)) } } case sPost.Type == "message" && sPost.SubType == "file_comment": if sPost.Comment == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.msg_no_comment.debug")) + mlog.Debug("Slack Import: Unable to import the message as it has no comments.") continue } else if sPost.Comment.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.msg_no_usr.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.Comment.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } newPost := model.Post{ @@ -272,10 +273,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportPost(&newPost) case sPost.Type == "message" && sPost.SubType == "bot_message": if botUser == nil { - l4g.Warn(utils.T("api.slackimport.slack_add_posts.bot_user_no_exists.warn")) + mlog.Warn("Slack Import: Unable to import the bot message as the bot user does not exist.") continue } else if sPost.BotId == "" { - l4g.Warn(utils.T("api.slackimport.slack_add_posts.no_bot_id.warn")) + mlog.Warn("Slack Import: Unable to import bot message as the BotId field is missing.") continue } @@ -296,10 +297,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportIncomingWebhookPost(post, props) case sPost.Type == "message" && (sPost.SubType == "channel_join" || sPost.SubType == "channel_leave"): if sPost.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.msg_no_usr.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } @@ -323,10 +324,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportPost(&newPost) case sPost.Type == "message" && sPost.SubType == "me_message": if sPost.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.without_user.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } newPost := model.Post{ @@ -338,10 +339,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportPost(&newPost) case sPost.Type == "message" && sPost.SubType == "channel_topic": if sPost.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.msg_no_usr.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } newPost := model.Post{ @@ -354,10 +355,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportPost(&newPost) case sPost.Type == "message" && sPost.SubType == "channel_purpose": if sPost.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.msg_no_usr.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } newPost := model.Post{ @@ -370,10 +371,10 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack a.OldImportPost(&newPost) case sPost.Type == "message" && sPost.SubType == "channel_name": if sPost.User == "" { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.msg_no_usr.debug")) + mlog.Debug("Slack Import: Unable to import the message as the user field is missing.") continue } else if users[sPost.User] == nil { - l4g.Debug(utils.T("api.slackimport.slack_add_posts.user_no_exists.debug"), sPost.User) + mlog.Debug(fmt.Sprintf("Slack Import: Unable to add the message as the Slack user %v does not exist in Mattermost.", sPost.User)) continue } newPost := model.Post{ @@ -385,7 +386,7 @@ func (a *App) SlackAddPosts(teamId string, channel *model.Channel, posts []Slack } a.OldImportPost(&newPost) default: - l4g.Warn(utils.T("api.slackimport.slack_add_posts.unsupported.warn"), sPost.Type, sPost.SubType) + mlog.Warn(fmt.Sprintf("Slack Import: Unable to import the message as its type is not supported: post_type=%v, post_subtype=%v.", sPost.Type, sPost.SubType)) } } } @@ -395,7 +396,7 @@ func (a *App) SlackUploadFile(sPost SlackPost, uploads map[string]*zip.File, tea if file, ok := uploads[sPost.File.Id]; ok { openFile, err := file.Open() if err != nil { - l4g.Warn(utils.T("api.slackimport.slack_add_posts.upload_file_open_failed.warn", map[string]interface{}{"FileId": sPost.File.Id, "Error": err.Error()})) + mlog.Warn("Slack Import: Unable to open the file {{.FileId}} from the Slack export: {{.Error}}.") return nil, false } defer openFile.Close() @@ -403,17 +404,17 @@ func (a *App) SlackUploadFile(sPost SlackPost, uploads map[string]*zip.File, tea timestamp := utils.TimeFromMillis(SlackConvertTimeStamp(sPost.TimeStamp)) uploadedFile, err := a.OldImportFile(timestamp, openFile, teamId, channelId, userId, filepath.Base(file.Name)) if err != nil { - l4g.Warn(utils.T("api.slackimport.slack_add_posts.upload_file_upload_failed.warn", map[string]interface{}{"FileId": sPost.File.Id, "Error": err.Error()})) + mlog.Warn("Slack Import: An error occurred when uploading file {{.FileId}}: {{.Error}}.") return nil, false } return uploadedFile, true } else { - l4g.Warn(utils.T("api.slackimport.slack_add_posts.upload_file_not_found.warn", map[string]interface{}{"FileId": sPost.File.Id})) + mlog.Warn("Slack Import: Unable to import file {{.FileId}} as the file is missing from the Slack export zip file.") return nil, false } } else { - l4g.Warn(utils.T("api.slackimport.slack_add_posts.upload_file_not_in_json.warn")) + mlog.Warn("Slack Import: Unable to attach the file to the post as the latter has no file section present in Slack export.") return nil, false } } @@ -421,7 +422,7 @@ func (a *App) SlackUploadFile(sPost SlackPost, uploads map[string]*zip.File, tea func (a *App) deactivateSlackBotUser(user *model.User) { _, err := a.UpdateActive(user, false) if err != nil { - l4g.Warn(utils.T("api.slackimport.slack_deactivate_bot_user.failed_to_deactivate", err)) + mlog.Warn("Slack Import: Unable to deactivate the user account used for the bot.") } } @@ -439,32 +440,32 @@ func (a *App) addSlackUsersToChannel(members []string, users map[string]*model.U func SlackSanitiseChannelProperties(channel model.Channel) model.Channel { if utf8.RuneCountInString(channel.DisplayName) > model.CHANNEL_DISPLAY_NAME_MAX_RUNES { - l4g.Warn("api.slackimport.slack_sanitise_channel_properties.display_name_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName}) + mlog.Warn(fmt.Sprint("api.slackimport.slack_sanitise_channel_properties.display_name_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName})) channel.DisplayName = truncateRunes(channel.DisplayName, model.CHANNEL_DISPLAY_NAME_MAX_RUNES) } if len(channel.Name) > model.CHANNEL_NAME_MAX_LENGTH { - l4g.Warn("api.slackimport.slack_sanitise_channel_properties.name_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName}) + mlog.Warn(fmt.Sprint("api.slackimport.slack_sanitise_channel_properties.name_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName})) channel.Name = channel.Name[0:model.CHANNEL_NAME_MAX_LENGTH] } if utf8.RuneCountInString(channel.Purpose) > model.CHANNEL_PURPOSE_MAX_RUNES { - l4g.Warn("api.slackimport.slack_sanitise_channel_properties.purpose_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName}) + mlog.Warn(fmt.Sprint("api.slackimport.slack_sanitise_channel_properties.purpose_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName})) channel.Purpose = truncateRunes(channel.Purpose, model.CHANNEL_PURPOSE_MAX_RUNES) } if utf8.RuneCountInString(channel.Header) > model.CHANNEL_HEADER_MAX_RUNES { - l4g.Warn("api.slackimport.slack_sanitise_channel_properties.header_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName}) + mlog.Warn(fmt.Sprint("api.slackimport.slack_sanitise_channel_properties.header_too_long.warn", map[string]interface{}{"ChannelName": channel.DisplayName})) channel.Header = truncateRunes(channel.Header, model.CHANNEL_HEADER_MAX_RUNES) } return channel } -func (a *App) SlackAddChannels(teamId string, slackchannels []SlackChannel, posts map[string][]SlackPost, users map[string]*model.User, uploads map[string]*zip.File, botUser *model.User, log *bytes.Buffer) map[string]*model.Channel { +func (a *App) SlackAddChannels(teamId string, slackchannels []SlackChannel, posts map[string][]SlackPost, users map[string]*model.User, uploads map[string]*zip.File, botUser *model.User, importerLog *bytes.Buffer) map[string]*model.Channel { // Write Header - log.WriteString(utils.T("api.slackimport.slack_add_channels.added")) - log.WriteString("=================\r\n\r\n") + importerLog.WriteString(utils.T("api.slackimport.slack_add_channels.added")) + importerLog.WriteString("=================\r\n\r\n") addedChannels := make(map[string]*model.Channel) for _, sChannel := range slackchannels { @@ -482,7 +483,7 @@ func (a *App) SlackAddChannels(teamId string, slackchannels []SlackChannel, post if result := <-a.Srv.Store.Channel().GetByName(teamId, sChannel.Name, true); result.Err == nil { // The channel already exists as an active channel. Merge with the existing one. mChannel = result.Data.(*model.Channel) - log.WriteString(utils.T("api.slackimport.slack_add_channels.merge", map[string]interface{}{"DisplayName": newChannel.DisplayName})) + importerLog.WriteString(utils.T("api.slackimport.slack_add_channels.merge", map[string]interface{}{"DisplayName": newChannel.DisplayName})) } else if result := <-a.Srv.Store.Channel().GetDeletedByName(teamId, sChannel.Name); result.Err == nil { // The channel already exists but has been deleted. Generate a random string for the handle instead. newChannel.Name = model.NewId() @@ -493,14 +494,14 @@ func (a *App) SlackAddChannels(teamId string, slackchannels []SlackChannel, post // Haven't found an existing channel to merge with. Try importing it as a new one. mChannel = a.OldImportChannel(&newChannel) if mChannel == nil { - l4g.Warn(utils.T("api.slackimport.slack_add_channels.import_failed.warn"), newChannel.DisplayName) - log.WriteString(utils.T("api.slackimport.slack_add_channels.import_failed", map[string]interface{}{"DisplayName": newChannel.DisplayName})) + mlog.Warn(fmt.Sprintf("Slack Import: Unable to import Slack channel: %s.", newChannel.DisplayName)) + importerLog.WriteString(utils.T("api.slackimport.slack_add_channels.import_failed", map[string]interface{}{"DisplayName": newChannel.DisplayName})) continue } } - a.addSlackUsersToChannel(sChannel.Members, users, mChannel, log) - log.WriteString(newChannel.DisplayName + "\r\n") + a.addSlackUsersToChannel(sChannel.Members, users, mChannel, importerLog) + importerLog.WriteString(newChannel.DisplayName + "\r\n") addedChannels[sChannel.Id] = mChannel a.SlackAddPosts(teamId, mChannel, posts[sChannel.Name], users, uploads, botUser) } @@ -513,7 +514,7 @@ func SlackConvertUserMentions(users []SlackUser, posts map[string][]SlackPost) m for _, user := range users { r, err := regexp.Compile("<@" + user.Id + `(\|` + user.Username + ")?>") if err != nil { - l4g.Warn(utils.T("api.slackimport.slack_convert_user_mentions.compile_regexp_failed.warn"), user.Id, user.Username) + mlog.Warn(fmt.Sprint("Slack Import: Unable to compile the @mention, matching regular expression for the Slack user {{.Username}} (id={{.UserID}}).", user.Id, user.Username), mlog.String("user_id", user.Id)) continue } regexes["@"+user.Username] = r @@ -541,7 +542,7 @@ func SlackConvertChannelMentions(channels []SlackChannel, posts map[string][]Sla for _, channel := range channels { r, err := regexp.Compile("<#" + channel.Id + `(\|` + channel.Name + ")?>") if err != nil { - l4g.Warn(utils.T("api.slackimport.slack_convert_channel_mentions.compile_regexp_failed.warn"), channel.Id, channel.Name) + mlog.Warn(fmt.Sprint("Slack Import: Unable to compile the !channel, matching regular expression for the Slack channel {{.ChannelName}} (id={{.ChannelID}}).", channel.Id, channel.Name)) continue } regexes["~"+channel.Name] = r diff --git a/app/status.go b/app/status.go index 64d5379ef..d8e93e2f1 100644 --- a/app/status.go +++ b/app/status.go @@ -4,8 +4,9 @@ package app import ( - l4g "github.com/alecthomas/log4go" + "fmt" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -208,7 +209,7 @@ func (a *App) SetStatusOnline(userId string, sessionId string, manual bool) { } if result := <-schan; result.Err != nil { - l4g.Error(utils.T("api.status.save_status.error"), userId, result.Err) + mlog.Error(fmt.Sprintf("Failed to save status for user_id=%v, err=%v", userId, result.Err), mlog.String("user_id", userId)) } } @@ -292,7 +293,7 @@ func (a *App) SaveAndBroadcastStatus(status *model.Status) *model.AppError { a.AddStatusCache(status) if result := <-a.Srv.Store.Status().SaveOrUpdate(status); result.Err != nil { - l4g.Error(utils.T("api.status.save_status.error"), status.UserId, result.Err) + mlog.Error(fmt.Sprintf("Failed to save status for user_id=%v, err=%v", status.UserId, result.Err)) } event := model.NewWebSocketEvent(model.WEBSOCKET_EVENT_STATUS_CHANGE, "", "", status.UserId, nil) @@ -320,7 +321,7 @@ func (a *App) SetStatusOutOfOffice(userId string) { a.AddStatusCache(status) if result := <-a.Srv.Store.Status().SaveOrUpdate(status); result.Err != nil { - l4g.Error(utils.T("api.status.save_status.error"), userId, result.Err) + mlog.Error(fmt.Sprintf("Failed to save status for user_id=%v, err=%v", userId, result.Err), mlog.String("user_id", userId)) } event := model.NewWebSocketEvent(model.WEBSOCKET_EVENT_STATUS_CHANGE, "", "", status.UserId, nil) diff --git a/app/team.go b/app/team.go index 47e28f2ed..78d932870 100644 --- a/app/team.go +++ b/app/team.go @@ -13,9 +13,9 @@ import ( "net/url" "strings" - l4g "github.com/alecthomas/log4go" "github.com/disintegration/imaging" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -350,7 +350,7 @@ func (a *App) JoinUserToTeam(team *model.Team, user *model.User, userRequestorId // Soft error if there is an issue joining the default channels if err := a.JoinDefaultChannels(team.Id, user, channelRole, userRequestorId); err != nil { - l4g.Error(utils.T("api.user.create_user.joining.error"), user.Id, team.Id, err) + mlog.Error(fmt.Sprintf("Encountered an issue joining default channels user_id=%s, team_id=%s, err=%v", user.Id, team.Id, err), mlog.String("user_id", user.Id)) } a.ClearSessionCacheForUser(user.Id) @@ -638,11 +638,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 { - l4g.Error(utils.T("api.channel.post_user_add_remove_message_and_forget.error"), err) + mlog.Error(fmt.Sprint("Failed to post join/leave message", err)) } } else { if err := a.postRemoveFromTeamMessage(user, channel); err != nil { - l4g.Error(utils.T("api.channel.post_user_add_remove_message_and_forget.error"), err) + mlog.Error(fmt.Sprint("Failed to post join/leave message", err)) } } } @@ -908,7 +908,7 @@ func (a *App) GetTeamIdFromQuery(query url.Values) (string, *model.AppError) { } else if len(inviteId) > 0 { if result := <-a.Srv.Store.Team().GetByInviteId(inviteId); result.Err != nil { // soft fail, so we still create user but don't auto-join team - l4g.Error("%v", result.Err) + mlog.Error(fmt.Sprintf("%v", result.Err)) } else { return result.Data.(*model.Team).Id, nil } diff --git a/app/user.go b/app/user.go index 34076555e..fd8b6b377 100644 --- a/app/user.go +++ b/app/user.go @@ -22,10 +22,10 @@ import ( "strconv" "strings" - l4g "github.com/alecthomas/log4go" "github.com/disintegration/imaging" "github.com/golang/freetype" "github.com/mattermost/mattermost-server/einterfaces" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -118,7 +118,7 @@ func (a *App) CreateUserWithInviteId(user *model.User, inviteId string) (*model. a.AddDirectChannels(team.Id, ruser) if err := a.SendWelcomeEmail(ruser.Id, ruser.Email, ruser.EmailVerified, ruser.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } return ruser, nil @@ -131,7 +131,7 @@ func (a *App) CreateUserAsAdmin(user *model.User) (*model.User, *model.AppError) } if err := a.SendWelcomeEmail(ruser.Id, ruser.Email, ruser.EmailVerified, ruser.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } return ruser, nil @@ -155,7 +155,7 @@ func (a *App) CreateUserFromSignup(user *model.User) (*model.User, *model.AppErr } if err := a.SendWelcomeEmail(ruser.Id, ruser.Email, ruser.EmailVerified, ruser.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } return ruser, nil @@ -172,7 +172,7 @@ func (a *App) IsUserSignUpAllowed() *model.AppError { func (a *App) IsFirstUserAccount() bool { if a.SessionCacheLength() == 0 { if cr := <-a.Srv.Store.User().GetTotalUsersCount(); cr.Err != nil { - l4g.Error(cr.Err) + mlog.Error(fmt.Sprint(cr.Err)) return false } else { count := cr.Data.(int64) @@ -227,20 +227,20 @@ func (a *App) createUser(user *model.User) (*model.User, *model.AppError) { } if result := <-a.Srv.Store.User().Save(user); result.Err != nil { - l4g.Error(utils.T("api.user.create_user.save.error"), result.Err) + mlog.Error(fmt.Sprintf("Couldn't save the user err=%v", result.Err)) return nil, result.Err } else { ruser := result.Data.(*model.User) if user.EmailVerified { if err := a.VerifyUserEmail(ruser.Id); err != nil { - l4g.Error(utils.T("api.user.create_user.verified.error"), err) + mlog.Error(fmt.Sprintf("Failed to set email verified err=%v", err)) } } pref := model.Preference{UserId: ruser.Id, Category: model.PREFERENCE_CATEGORY_TUTORIAL_STEPS, Name: ruser.Id, Value: "0"} if presult := <-a.Srv.Store.Preference().Save(&model.Preferences{pref}); presult.Err != nil { - l4g.Error(utils.T("api.user.create_user.tutorial.error"), presult.Err.Message) + mlog.Error(fmt.Sprintf("Encountered error saving tutorial preference, err=%v", presult.Err.Message)) } ruser.Sanitize(map[string]bool{}) @@ -306,7 +306,7 @@ func (a *App) CreateOAuthUser(service string, userData io.Reader, teamId string) err = a.AddDirectChannels(teamId, user) if err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } @@ -851,7 +851,7 @@ func (a *App) SetProfileImageFromFile(userId string, file multipart.File) *model a.InvalidateCacheForUser(userId) if user, err := a.GetUser(userId); err != nil { - l4g.Error(utils.T("api.user.get_me.getting.error"), userId) + mlog.Error(fmt.Sprintf("Error in getting users profile for id=%v forcing logout", userId), mlog.String("user_id", userId)) } else { options := a.Config().GetSanitizeOptions() user.SanitizeProfile(options) @@ -1056,14 +1056,14 @@ func (a *App) UpdateUser(user *model.User, sendNotifications bool) (*model.User, if rusers[0].Email != rusers[1].Email { a.Go(func() { if err := a.SendEmailChangeEmail(rusers[1].Email, rusers[0].Email, rusers[0].Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) if a.Config().EmailSettings.RequireEmailVerification { a.Go(func() { if err := a.SendEmailVerification(rusers[0]); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) } @@ -1072,7 +1072,7 @@ func (a *App) UpdateUser(user *model.User, sendNotifications bool) (*model.User, if rusers[0].Username != rusers[1].Username { a.Go(func() { if err := a.SendChangeUsernameEmail(rusers[1].Username, rusers[0].Username, rusers[0].Email, rusers[0].Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) } @@ -1117,12 +1117,12 @@ func (a *App) UpdateMfa(activate bool, userId, token string) *model.AppError { var err *model.AppError if user, err = a.GetUser(userId); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) return } if err := a.SendMfaChangeEmail(user.Email, activate, user.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) @@ -1160,7 +1160,7 @@ func (a *App) UpdatePasswordSendEmail(user *model.User, newPassword, method stri a.Go(func() { if err := a.SendPasswordChangeEmail(user.Email, method, user.Locale, a.GetSiteURL()); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } }) @@ -1194,7 +1194,7 @@ func (a *App) ResetPasswordFromToken(userSuppliedTokenString, newPassword string } if err := a.DeleteToken(token); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } return nil @@ -1278,7 +1278,7 @@ func (a *App) UpdateUserRoles(userId string, newRoles string, sendWebSocketEvent if result := <-schan; result.Err != nil { // soft error since the user roles were still updated - l4g.Error(result.Err) + mlog.Error(fmt.Sprint(result.Err)) } a.ClearSessionCacheForUser(user.Id) @@ -1294,9 +1294,9 @@ func (a *App) UpdateUserRoles(userId string, newRoles string, sendWebSocketEvent } func (a *App) PermanentDeleteUser(user *model.User) *model.AppError { - l4g.Warn(utils.T("api.user.permanent_delete_user.attempting.warn"), user.Email, user.Id) + mlog.Warn(fmt.Sprintf("Attempting to permanently delete account %v id=%v", user.Email, user.Id), mlog.String("user_id", user.Id)) if user.IsInRole(model.SYSTEM_ADMIN_ROLE_ID) { - l4g.Warn(utils.T("api.user.permanent_delete_user.system_admin.warn"), user.Email) + mlog.Warn(fmt.Sprintf("You are deleting %v that is a system administrator. You may need to set another account as the system administrator using the command line tools.", user.Email)) } if _, err := a.UpdateActive(user, false); err != nil { @@ -1351,7 +1351,7 @@ func (a *App) PermanentDeleteUser(user *model.User) *model.AppError { return result.Err } - l4g.Warn(utils.T("api.user.permanent_delete_user.deleted.warn"), user.Email, user.Id) + mlog.Warn(fmt.Sprintf("Permanently deleted account %v id=%v", user.Email, user.Id), mlog.String("user_id", user.Id)) return nil } @@ -1395,7 +1395,7 @@ func (a *App) VerifyEmailFromToken(userSuppliedTokenString string) *model.AppErr return err } if err := a.DeleteToken(token); err != nil { - l4g.Error(err.Error()) + mlog.Error(err.Error()) } } diff --git a/app/web_conn.go b/app/web_conn.go index 9ae5505b2..9d8134f34 100644 --- a/app/web_conn.go +++ b/app/web_conn.go @@ -8,10 +8,9 @@ import ( "sync/atomic" "time" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" - "github.com/mattermost/mattermost-server/utils" - l4g "github.com/alecthomas/log4go" "github.com/gorilla/websocket" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -138,9 +137,9 @@ func (c *WebConn) readPump() { if err := c.WebSocket.ReadJSON(&req); err != nil { // browsers will appear as CloseNoStatusReceived if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { - l4g.Debug(fmt.Sprintf("websocket.read: client side closed socket userId=%v", c.UserId)) + mlog.Debug(fmt.Sprintf("websocket.read: client side closed socket userId=%v", c.UserId)) } else { - l4g.Debug(fmt.Sprintf("websocket.read: closing websocket for userId=%v error=%v", c.UserId, err.Error())) + mlog.Debug(fmt.Sprintf("websocket.read: closing websocket for userId=%v error=%v", c.UserId, err.Error())) } return @@ -177,7 +176,7 @@ func (c *WebConn) writePump() { if msg.EventType() == model.WEBSOCKET_EVENT_TYPING || msg.EventType() == model.WEBSOCKET_EVENT_STATUS_CHANGE || msg.EventType() == model.WEBSOCKET_EVENT_CHANNEL_VIEWED { - l4g.Info(fmt.Sprintf("websocket.slow: dropping message userId=%v type=%v channelId=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId)) + mlog.Info(fmt.Sprintf("websocket.slow: dropping message userId=%v type=%v channelId=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId)) skipSend = true } } @@ -196,9 +195,9 @@ func (c *WebConn) writePump() { if len(c.Send) >= SEND_DEADLOCK_WARN { if evtOk { - l4g.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v channelId=%v size=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId, len(msg.ToJson()))) + mlog.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v channelId=%v size=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId, len(msg.ToJson()))) } else { - l4g.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v size=%v", c.UserId, msg.EventType(), len(msg.ToJson()))) + mlog.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v size=%v", c.UserId, msg.EventType(), len(msg.ToJson()))) } } @@ -206,9 +205,9 @@ func (c *WebConn) writePump() { if err := c.WebSocket.WriteMessage(websocket.TextMessage, msgBytes); err != nil { // browsers will appear as CloseNoStatusReceived if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { - l4g.Debug(fmt.Sprintf("websocket.send: client side closed socket userId=%v", c.UserId)) + mlog.Debug(fmt.Sprintf("websocket.send: client side closed socket userId=%v", c.UserId)) } else { - l4g.Debug(fmt.Sprintf("websocket.send: closing websocket for userId=%v, error=%v", c.UserId, err.Error())) + mlog.Debug(fmt.Sprintf("websocket.send: closing websocket for userId=%v, error=%v", c.UserId, err.Error())) } return @@ -226,9 +225,9 @@ func (c *WebConn) writePump() { if err := c.WebSocket.WriteMessage(websocket.PingMessage, []byte{}); err != nil { // browsers will appear as CloseNoStatusReceived if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { - l4g.Debug(fmt.Sprintf("websocket.ticker: client side closed socket userId=%v", c.UserId)) + mlog.Debug(fmt.Sprintf("websocket.ticker: client side closed socket userId=%v", c.UserId)) } else { - l4g.Debug(fmt.Sprintf("websocket.ticker: closing websocket for userId=%v error=%v", c.UserId, err.Error())) + mlog.Debug(fmt.Sprintf("websocket.ticker: closing websocket for userId=%v error=%v", c.UserId, err.Error())) } return @@ -237,7 +236,7 @@ func (c *WebConn) writePump() { return case <-authTicker.C: if c.GetSessionToken() == "" { - l4g.Debug(fmt.Sprintf("websocket.authTicker: did not authenticate ip=%v", c.WebSocket.RemoteAddr())) + mlog.Debug(fmt.Sprintf("websocket.authTicker: did not authenticate ip=%v", c.WebSocket.RemoteAddr())) return } authTicker.Stop() @@ -261,7 +260,7 @@ func (webCon *WebConn) IsAuthenticated() bool { session, err := webCon.App.GetSession(webCon.GetSessionToken()) if err != nil { - l4g.Error(utils.T("api.websocket.invalid_session.error"), err.Error()) + mlog.Error(fmt.Sprintf("Invalid session err=%v", err.Error())) webCon.SetSessionToken("") webCon.SetSession(nil) webCon.SetSessionExpiresAt(0) @@ -334,7 +333,7 @@ func (webCon *WebConn) ShouldSendEvent(msg *model.WebSocketEvent) bool { if webCon.AllChannelMembers == nil { if result := <-webCon.App.Srv.Store.Channel().GetAllChannelMembersForUser(webCon.UserId, true); result.Err != nil { - l4g.Error("webhub.shouldSendEvent: " + result.Err.Error()) + mlog.Error("webhub.shouldSendEvent: " + result.Err.Error()) return false } else { webCon.AllChannelMembers = result.Data.(map[string]string) @@ -365,7 +364,7 @@ func (webCon *WebConn) IsMemberOfTeam(teamId string) bool { if currentSession == nil || len(currentSession.Token) == 0 { session, err := webCon.App.GetSession(webCon.GetSessionToken()) if err != nil { - l4g.Error(utils.T("api.websocket.invalid_session.error"), err.Error()) + mlog.Error(fmt.Sprintf("Invalid session err=%v", err.Error())) return false } else { webCon.SetSession(session) diff --git a/app/web_hub.go b/app/web_hub.go index 971b03481..18eb97c8e 100644 --- a/app/web_hub.go +++ b/app/web_hub.go @@ -13,10 +13,8 @@ import ( "sync/atomic" "time" - l4g "github.com/alecthomas/log4go" - + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" - "github.com/mattermost/mattermost-server/utils" ) const ( @@ -66,7 +64,7 @@ func (a *App) TotalWebsocketConnections() int { func (a *App) HubStart() { // Total number of hubs is twice the number of CPUs. numberOfHubs := runtime.NumCPU() * 2 - l4g.Info(utils.T("api.web_hub.start.starting.debug"), numberOfHubs) + mlog.Info(fmt.Sprintf("Starting %v websocket hubs", numberOfHubs)) a.Hubs = make([]*Hub, numberOfHubs) a.HubsStopCheckingForDeadlock = make(chan bool, 1) @@ -89,7 +87,7 @@ func (a *App) HubStart() { case <-ticker.C: for _, hub := range a.Hubs { if len(hub.broadcast) >= DEADLOCK_WARN { - l4g.Error("Hub processing might be deadlock on hub %v goroutine %v with %v events in the buffer", hub.connectionIndex, hub.goroutineId, len(hub.broadcast)) + mlog.Error(fmt.Sprintf("Hub processing might be deadlock on hub %v goroutine %v with %v events in the buffer", hub.connectionIndex, hub.goroutineId, len(hub.broadcast))) buf := make([]byte, 1<<16) runtime.Stack(buf, true) output := fmt.Sprintf("%s", buf) @@ -97,7 +95,7 @@ func (a *App) HubStart() { for _, part := range splits { if strings.Contains(part, fmt.Sprintf("%v", hub.goroutineId)) { - l4g.Error("Trace for possible deadlock goroutine %v", part) + mlog.Error(fmt.Sprintf("Trace for possible deadlock goroutine %v", part)) } } } @@ -111,12 +109,12 @@ func (a *App) HubStart() { } func (a *App) HubStop() { - l4g.Info(utils.T("api.web_hub.start.stopping.debug")) + mlog.Info("stopping websocket hub connections") select { case a.HubsStopCheckingForDeadlock <- true: default: - l4g.Warn("We appear to have already sent the stop checking for deadlocks command") + mlog.Warn("We appear to have already sent the stop checking for deadlocks command") } for _, hub := range a.Hubs { @@ -367,7 +365,7 @@ func (h *Hub) Start() { doStart = func() { h.goroutineId = getGoroutineId() - l4g.Debug("Hub for index %v is starting with goroutine %v", h.connectionIndex, h.goroutineId) + mlog.Debug(fmt.Sprintf("Hub for index %v is starting with goroutine %v", h.connectionIndex, h.goroutineId)) connections := newHubConnectionIndex() @@ -404,7 +402,7 @@ func (h *Hub) Start() { select { case webCon.Send <- msg: default: - l4g.Error(fmt.Sprintf("webhub.broadcast: cannot send, closing websocket for userId=%v", webCon.UserId)) + mlog.Error(fmt.Sprintf("webhub.broadcast: cannot send, closing websocket for userId=%v", webCon.UserId)) close(webCon.Send) connections.Remove(webCon) } @@ -438,12 +436,12 @@ func (h *Hub) Start() { doRecover = func() { if !h.ExplicitStop { if r := recover(); r != nil { - l4g.Error(fmt.Sprintf("Recovering from Hub panic. Panic was: %v", r)) + mlog.Error(fmt.Sprintf("Recovering from Hub panic. Panic was: %v", r)) } else { - l4g.Error("Webhub stopped unexpectedly. Recovering.") + mlog.Error("Webhub stopped unexpectedly. Recovering.") } - l4g.Error(string(debug.Stack())) + mlog.Error(string(debug.Stack())) go doRecoverableStart() } diff --git a/app/webhook.go b/app/webhook.go index 5c3e963ce..a5ab28952 100644 --- a/app/webhook.go +++ b/app/webhook.go @@ -4,13 +4,14 @@ package app import ( + "fmt" "io" "net/http" "regexp" "strings" "unicode/utf8" - l4g "github.com/alecthomas/log4go" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/store" "github.com/mattermost/mattermost-server/utils" @@ -107,7 +108,7 @@ func (a *App) TriggerWebhook(payload *model.OutgoingWebhookPayload, hook *model. req.Header.Set("Content-Type", contentType) req.Header.Set("Accept", "application/json") if resp, err := a.HTTPClient(false).Do(req); err != nil { - l4g.Error(utils.T("api.post.handle_webhook_events_and_forget.event_post.error"), err.Error()) + mlog.Error(fmt.Sprintf("Event POST failed, err=%s", err.Error())) } else { defer consumeAndClose(resp) @@ -134,7 +135,7 @@ func (a *App) TriggerWebhook(payload *model.OutgoingWebhookPayload, hook *model. } if _, err := a.CreateWebhookPost(hook.CreatorId, channel, text, webhookResp.Username, webhookResp.IconURL, webhookResp.Props, webhookResp.Type, postRootId); err != nil { - l4g.Error(utils.T("api.post.handle_webhook_events_and_forget.create_post.error"), err) + mlog.Error(fmt.Sprintf("Failed to create response post, err=%v", err)) } } } diff --git a/app/websocket_router.go b/app/websocket_router.go index 6bc3a6ff7..6c5e142a1 100644 --- a/app/websocket_router.go +++ b/app/websocket_router.go @@ -4,10 +4,10 @@ package app import ( - l4g "github.com/alecthomas/log4go" - + "fmt" "net/http" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" "github.com/mattermost/mattermost-server/utils" ) @@ -91,7 +91,7 @@ func (wr *WebSocketRouter) ServeWebSocket(conn *WebConn, r *model.WebSocketReque } func ReturnWebSocketError(conn *WebConn, r *model.WebSocketRequest, err *model.AppError) { - l4g.Error(utils.T("api.web_socket_router.log.error"), r.Seq, conn.UserId, err.SystemMessage(utils.T), err.DetailedError) + mlog.Error(fmt.Sprintf("websocket routing error: seq=%v uid=%v %v [details: %v]", r.Seq, conn.UserId, err.SystemMessage(utils.T), err.DetailedError)) err.DetailedError = "" errorResp := model.NewWebSocketError(r.Seq, err) -- cgit v1.2.3-1-g7c22