diff --git a/api4/graphql.go b/api4/graphql.go index 41208ec1d0..564a543fd2 100644 --- a/api4/graphql.go +++ b/api4/graphql.go @@ -48,7 +48,7 @@ func (api *API) InitGraphQL() error { var err error opts := []graphql.SchemaOpt{ graphql.UseFieldResolvers(), - graphql.Logger(mlog.NewGraphQLLogger(api.srv.Log)), + graphql.Logger(mlog.NewGraphQLLogger(api.srv.Log())), graphql.MaxParallelism(loaderBatchCapacity), // This is dangerous if the query // uses any non-dataloader backed object. So we need to be a bit careful here. } diff --git a/app/admin.go b/app/admin.go index 3a139ef2e2..7b015be519 100644 --- a/app/admin.go +++ b/app/admin.go @@ -67,7 +67,7 @@ func (s *Server) GetLogsSkipSend(page, perPage int) ([]string, *model.AppError) var lines []string if *s.platform.Config().LogSettings.EnableFile { - s.Log.Flush() + s.Log().Flush() logFile := config.GetLogFileLocation(*s.platform.Config().LogSettings.FileLocation) file, err := os.Open(logFile) if err != nil { diff --git a/app/app.go b/app/app.go index bcb6149b4d..498bd64b2b 100644 --- a/app/app.go +++ b/app/app.go @@ -89,10 +89,10 @@ func (a *App) Srv() *Server { return a.ch.srv } func (a *App) Log() *mlog.Logger { - return a.ch.srv.Log + return a.ch.srv.Log() } func (a *App) NotificationsLog() *mlog.Logger { - return a.ch.srv.NotificationsLog + return a.ch.srv.NotificationsLog() } func (a *App) AccountMigration() einterfaces.AccountMigrationInterface { diff --git a/app/channel.go b/app/channel.go index de39d06c3a..15cadcf709 100644 --- a/app/channel.go +++ b/app/channel.go @@ -29,21 +29,21 @@ type channelsWrapper struct { } func (s *channelsWrapper) GetDirectChannel(userID1, userID2 string) (*model.Channel, *model.AppError) { - return s.srv.getDirectChannel(request.EmptyContext(s.srv.GetLogger()), userID1, userID2) + return s.srv.getDirectChannel(request.EmptyContext(s.srv.Log()), userID1, userID2) } // GetChannelByID gets a Channel by its ID. func (s *channelsWrapper) GetChannelByID(channelID string) (*model.Channel, *model.AppError) { - return s.srv.getChannel(request.EmptyContext(s.srv.GetLogger()), channelID) + return s.srv.getChannel(request.EmptyContext(s.srv.Log()), channelID) } // GetChannelMember gets a channel member by userID. func (s *channelsWrapper) GetChannelMember(channelID string, userID string) (*model.ChannelMember, *model.AppError) { - return s.srv.getChannelMember(request.EmptyContext(s.srv.GetLogger()), channelID, userID) + return s.srv.getChannelMember(request.EmptyContext(s.srv.Log()), channelID, userID) } func (s *channelsWrapper) GetChannelsForTeamForUser(teamID string, userID string, opts *model.ChannelSearchOpts) (model.ChannelList, *model.AppError) { - return s.srv.getChannelsForTeamForUser(request.EmptyContext(s.srv.GetLogger()), teamID, userID, opts) + return s.srv.getChannelsForTeamForUser(request.EmptyContext(s.srv.Log()), teamID, userID, opts) } // Ensure the wrapper implements the product service. diff --git a/app/channels.go b/app/channels.go index 4bb8cd7de0..ea08ac8086 100644 --- a/app/channels.go +++ b/app/channels.go @@ -101,7 +101,7 @@ func init() { func NewChannels(s *Server, services map[ServiceKey]any) (*Channels, error) { ch := &Channels{ srv: s, - imageProxy: imageproxy.MakeImageProxy(s.platform, s.httpService, s.Log), + imageProxy: imageproxy.MakeImageProxy(s.platform, s.httpService, s.Log()), uploadLockMap: map[string]bool{}, } @@ -167,12 +167,12 @@ func NewChannels(s *Server, services map[ServiceKey]any) (*Channels, error) { if samlInterfaceNew != nil { ch.Saml = samlInterfaceNew(New(ServerConnector(ch))) if err := ch.Saml.ConfigureSP(); err != nil { - s.Log.Error("An error occurred while configuring SAML Service Provider", mlog.Err(err)) + s.Log().Error("An error occurred while configuring SAML Service Provider", mlog.Err(err)) } ch.AddConfigListener(func(_, _ *model.Config) { if err := ch.Saml.ConfigureSP(); err != nil { - s.Log.Error("An error occurred while configuring SAML Service Provider", mlog.Err(err)) + s.Log().Error("An error occurred while configuring SAML Service Provider", mlog.Err(err)) } }) } @@ -235,7 +235,7 @@ func NewChannels(s *Server, services map[ServiceKey]any) (*Channels, error) { func (ch *Channels) Start() error { // Start plugins - ctx := request.EmptyContext(ch.srv.GetLogger()) + ctx := request.EmptyContext(ch.srv.Log()) ch.initPlugins(ctx, *ch.cfgSvc.Config().PluginSettings.Directory, *ch.cfgSvc.Config().PluginSettings.ClientDirectory) ch.AddConfigListener(func(prevCfg, cfg *model.Config) { @@ -243,7 +243,7 @@ func (ch *Channels) Start() error { // to ensure we don't re-init plugins unnecessarily. diffs, err := config.Diff(prevCfg, cfg) if err != nil { - ch.srv.Log.Warn("Error in comparing configs", mlog.Err(err)) + ch.srv.Log().Warn("Error in comparing configs", mlog.Err(err)) return } diff --git a/app/cluster.go b/app/cluster.go index 9cc0d56e0b..4e3b90dbe0 100644 --- a/app/cluster.go +++ b/app/cluster.go @@ -84,7 +84,7 @@ func (s *Server) RemoveClusterLeaderChangedListener(id string) { } func (s *Server) InvokeClusterLeaderChangedListeners() { - s.Log.Info("Cluster leader changed. Invoking ClusterLeaderChanged listeners.") + s.Log().Info("Cluster leader changed. Invoking ClusterLeaderChanged listeners.") // This needs to be run in a separate goroutine otherwise a recursive lock happens // because the listener function eventually ends up calling .IsLeader(). // Fixing this would require the changed event to pass the leader directly, but that diff --git a/app/integration_action.go b/app/integration_action.go index 18e41fde75..63a4278782 100644 --- a/app/integration_action.go +++ b/app/integration_action.go @@ -594,7 +594,7 @@ func (a *App) OpenInteractiveDialog(request model.OpenDialogRequest) *model.AppE jsonRequest, err := json.Marshal(request) if err != nil { - a.ch.srv.GetLogger().Warn("Error encoding request", mlog.Err(err)) + a.ch.srv.Log().Warn("Error encoding request", mlog.Err(err)) } message := model.NewWebSocketEvent(model.WebsocketEventOpenDialog, "", "", userID, nil) diff --git a/app/license.go b/app/license.go index 81cc6cd16e..f812ae9527 100644 --- a/app/license.go +++ b/app/license.go @@ -366,7 +366,7 @@ func (s *Server) RequestTrialLicense(trialRequest *model.TrialLicenseRequest) *m var licenseResponse map[string]string err = json.NewDecoder(resp.Body).Decode(&licenseResponse) if err != nil { - s.GetLogger().Warn("Error decoding license response", mlog.Err(err)) + s.Log().Warn("Error decoding license response", mlog.Err(err)) } if _, ok := licenseResponse["license"]; !ok { diff --git a/app/options.go b/app/options.go index 6452fd9092..842040e176 100644 --- a/app/options.go +++ b/app/options.go @@ -55,7 +55,6 @@ func Config(dsn string, readOnly bool, configDefaults *model.Config) Option { platformCfg := platform.ServiceConfig{ ConfigStore: configStore, - Logger: s.Log, StartMetrics: s.startMetrics, Cluster: s.Cluster, } @@ -78,7 +77,6 @@ func ConfigStore(configStore *config.Store) Option { return func(s *Server) error { platformCfg := platform.ServiceConfig{ ConfigStore: configStore, - Logger: s.Log, StartMetrics: s.startMetrics, Cluster: s.Cluster, } @@ -127,9 +125,15 @@ func StartSearchEngine(s *Server) error { return nil } +// SetLogger requires platform service to be initialized before calling. +// If not, logger should be set after platform service are initialized. func SetLogger(logger *mlog.Logger) Option { return func(s *Server) error { - s.Log = logger + if s.platform == nil { + return errors.New("platform service is not initialized") + } + + s.platform.SetLogger(logger) return nil } } diff --git a/app/platform/config.go b/app/platform/config.go index dbe0cbf85e..ab6c5e44b8 100644 --- a/app/platform/config.go +++ b/app/platform/config.go @@ -21,7 +21,6 @@ import ( type ServiceConfig struct { // Mandatory fields ConfigStore *config.Store - Logger *mlog.Logger StartMetrics bool // TODO: find an elegant way to start/stop metrics server by default // Optional fields Metrics einterfaces.MetricsInterface @@ -34,16 +33,6 @@ func (c *ServiceConfig) validate() error { return errors.New("ConfigStore is required") } - if c.Logger == nil { - var err error - // If Logger is not set, use a default logger temporarily. - // this should be removed once the logger is properly configured with the service config. - // MM-45841 - c.Logger, err = mlog.NewLogger() - if err != nil { - return err - } - } return nil } diff --git a/app/platform/log.go b/app/platform/log.go new file mode 100644 index 0000000000..0cb96dab85 --- /dev/null +++ b/app/platform/log.go @@ -0,0 +1,117 @@ +// Copyright (c) 2015-present Mattermost, Inc. All Rights Reserved. +// See LICENSE.txt for license information. + +package platform + +import ( + "context" + "errors" + "fmt" + "time" + + "github.com/mattermost/mattermost-server/v6/config" + "github.com/mattermost/mattermost-server/v6/model" + "github.com/mattermost/mattermost-server/v6/shared/mlog" +) + +func (ps *PlatformService) ReconfigureLogger() error { + return ps.initLogging() +} + +// initLogging initializes and configures the logger(s). This may be called more than once. +func (ps *PlatformService) initLogging() error { + // create the app logger if needed + if ps.logger == nil { + var err error + ps.logger, err = mlog.NewLogger() + if err != nil { + return err + } + + logCfg, err := config.MloggerConfigFromLoggerConfig(&ps.Config().LogSettings, nil, config.GetLogFileLocation) + if err != nil { + return err + } + + if errCfg := ps.logger.ConfigureTargets(logCfg, nil); errCfg != nil { + return fmt.Errorf("failed to configure test logger: %w", errCfg) + } + } + + // create notification logger if needed + if ps.notificationsLogger == nil { + l, err := mlog.NewLogger() + if err != nil { + return err + } + ps.notificationsLogger = l.With(mlog.String("logSource", "notifications")) + } + + if err := ps.ConfigureLogger("logging", ps.logger, &ps.Config().LogSettings, config.GetLogFileLocation); err != nil { + // if the config is locked then a unit test has already configured and locked the logger; not an error. + if !errors.Is(err, mlog.ErrConfigurationLock) { + // revert to default logger if the config is invalid + mlog.InitGlobalLogger(nil) + return err + } + } + + // Redirect default Go logger to app logger. + ps.logger.RedirectStdLog(mlog.LvlStdLog) + + // Use the app logger as the global logger (eventually remove all instances of global logging). + mlog.InitGlobalLogger(ps.logger) + + notificationLogSettings := config.GetLogSettingsFromNotificationsLogSettings(&ps.Config().NotificationLogSettings) + if err := ps.ConfigureLogger("notification logging", ps.notificationsLogger, notificationLogSettings, config.GetNotificationsLogFileLocation); err != nil { + if !errors.Is(err, mlog.ErrConfigurationLock) { + mlog.Error("Error configuring notification logger", mlog.Err(err)) + return err + } + } + + return nil +} + +func (ps *PlatformService) Logger() *mlog.Logger { + return ps.logger +} + +func (ps *PlatformService) NotificationsLogger() *mlog.Logger { + return ps.notificationsLogger +} + +func (ps *PlatformService) EnableLoggingMetrics() { + if ps.metrics == nil || ps.metrics.metricsImpl == nil { + return + } + + ps.logger.SetMetricsCollector(ps.metrics.metricsImpl.GetLoggerMetricsCollector(), mlog.DefaultMetricsUpdateFreqMillis) + + // logging config needs to be reloaded when metrics collector is added or changed. + if err := ps.initLogging(); err != nil { + mlog.Error("Error re-configuring logging for metrics") + return + } + + mlog.Debug("Logging metrics enabled") +} + +// RemoveUnlicensedLogTargets removes any unlicensed log target types. +func (ps *PlatformService) RemoveUnlicensedLogTargets(license *model.License) { + if license != nil && *license.Features.AdvancedLogging { + // advanced logging enabled via license; no need to remove any targets + return + } + + timeoutCtx, cancelCtx := context.WithTimeout(context.Background(), time.Second*10) + defer cancelCtx() + + ps.logger.RemoveTargets(timeoutCtx, func(ti mlog.TargetInfo) bool { + return ti.Type != "*targets.Writer" && ti.Type != "*targets.File" + }) + + ps.notificationsLogger.RemoveTargets(timeoutCtx, func(ti mlog.TargetInfo) bool { + return ti.Type != "*targets.Writer" && ti.Type != "*targets.File" + }) +} diff --git a/app/platform/service.go b/app/platform/service.go index 2db592adc2..4f85ac5c52 100644 --- a/app/platform/service.go +++ b/app/platform/service.go @@ -20,7 +20,9 @@ import ( type PlatformService struct { serviceConfig ServiceConfig configStore *config.Store - logger *mlog.Logger + + logger *mlog.Logger + notificationsLogger *mlog.Logger metrics *platformMetrics @@ -44,10 +46,13 @@ func New(sc ServiceConfig) (*PlatformService, error) { ps := &PlatformService{ serviceConfig: sc, configStore: sc.ConfigStore, - logger: sc.Logger, cluster: sc.Cluster, } + if err := ps.initLogging(); err != nil { + return nil, fmt.Errorf("failed to initialize logging: %w", err) + } + if err := ps.resetMetrics(sc.Metrics, ps.configStore.Get); err != nil { return nil, err } @@ -77,3 +82,7 @@ func (ps *PlatformService) ShutdownConfig() error { func (ps *PlatformService) SetTelemetryId(id string) { ps.telemetryId = id } + +func (ps *PlatformService) SetLogger(logger *mlog.Logger) { + ps.logger = logger +} diff --git a/app/plugin.go b/app/plugin.go index 35bb276b41..261c395e7f 100644 --- a/app/plugin.go +++ b/app/plugin.go @@ -110,7 +110,7 @@ func (ch *Channels) syncPluginsActiveState() { if *config.Enable { availablePlugins, err := pluginsEnvironment.Available() if err != nil { - ch.srv.Log.Error("Unable to get available plugins", mlog.Err(err)) + ch.srv.Log().Error("Unable to get available plugins", mlog.Err(err)) return } @@ -162,14 +162,14 @@ func (ch *Channels) syncPluginsActiveState() { pluginID := plugin.Manifest.Id updatedManifest, activated, err := pluginsEnvironment.Activate(pluginID) if err != nil { - plugin.WrapLogger(ch.srv.Log).Error("Unable to activate plugin", mlog.Err(err)) + plugin.WrapLogger(ch.srv.Log()).Error("Unable to activate plugin", mlog.Err(err)) return } if activated { // Notify all cluster clients if ready if err := ch.notifyPluginEnabled(updatedManifest); err != nil { - ch.srv.Log.Error("Failed to notify cluster on plugin enable", mlog.Err(err)) + ch.srv.Log().Error("Failed to notify cluster on plugin enable", mlog.Err(err)) } } }(plugin) @@ -209,7 +209,7 @@ func (ch *Channels) initPlugins(c *request.Context, pluginDir, webappPluginDir s return } - ch.srv.Log.Info("Starting up plugins") + ch.srv.Log().Info("Starting up plugins") if err := os.Mkdir(pluginDir, 0744); err != nil && !os.IsExist(err) { mlog.Error("Failed to start up plugins", mlog.Err(err)) @@ -225,7 +225,7 @@ func (ch *Channels) initPlugins(c *request.Context, pluginDir, webappPluginDir s return New(ServerConnector(ch)).NewPluginAPI(c, manifest) } - env, err := plugin.NewEnvironment(newAPIFunc, NewDriverImpl(ch.srv), pluginDir, webappPluginDir, ch.srv.Log, ch.srv.GetMetrics()) + env, err := plugin.NewEnvironment(newAPIFunc, NewDriverImpl(ch.srv), pluginDir, webappPluginDir, ch.srv.Log(), ch.srv.GetMetrics()) if err != nil { mlog.Error("Failed to start up plugins", mlog.Err(err)) return @@ -263,7 +263,7 @@ func (ch *Channels) initPlugins(c *request.Context, pluginDir, webappPluginDir s if pluginsEnvironment := ch.GetPluginsEnvironment(); pluginsEnvironment != nil { pluginsEnvironment.RunMultiPluginHook(func(hooks plugin.Hooks) bool { if err := hooks.OnConfigurationChange(); err != nil { - ch.srv.Log.Error("Plugin OnConfigurationChange hook failed", mlog.Err(err)) + ch.srv.Log().Error("Plugin OnConfigurationChange hook failed", mlog.Err(err)) } return true }, plugin.OnConfigurationChangeID) @@ -1018,7 +1018,7 @@ func (ch *Channels) installFeatureFlagPlugins() { // Skip installing if the plugin has been previously disabled. pluginState := ch.cfgSvc.Config().PluginSettings.PluginStates[pluginID] if pluginState != nil && !pluginState.Enable { - ch.srv.Log.Debug("Not auto installing/upgrade because plugin was disabled", mlog.String("plugin_id", pluginID), mlog.String("version", version)) + ch.srv.Log().Debug("Not auto installing/upgrade because plugin was disabled", mlog.String("plugin_id", pluginID), mlog.String("version", version)) continue } @@ -1036,17 +1036,17 @@ func (ch *Channels) installFeatureFlagPlugins() { if !inCloud && pluginExists { parsedVersion, err := semver.Parse(version) if err != nil { - ch.srv.Log.Debug("Bad version from feature flag", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", version)) + ch.srv.Log().Debug("Bad version from feature flag", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", version)) return } parsedExistingVersion, err := semver.Parse(pluginStatus.Version) if err != nil { - ch.srv.Log.Debug("Bad version from plugin manifest", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", pluginStatus.Version)) + ch.srv.Log().Debug("Bad version from plugin manifest", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", pluginStatus.Version)) return } if parsedVersion.LTE(parsedExistingVersion) { - ch.srv.Log.Debug("Skip installation because given version was a downgrade and on-prem installations should not downgrade.", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", pluginStatus.Version)) + ch.srv.Log().Debug("Skip installation because given version was a downgrade and on-prem installations should not downgrade.", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", pluginStatus.Version)) return } } @@ -1056,12 +1056,12 @@ func (ch *Channels) installFeatureFlagPlugins() { Version: version, }) if err != nil { - ch.srv.Log.Debug("Unable to install plugin from FF manifest", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", version)) + ch.srv.Log().Debug("Unable to install plugin from FF manifest", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", version)) } else { if err := ch.enablePlugin(pluginID); err != nil { - ch.srv.Log.Debug("Unable to enable plugin installed from feature flag.", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", version)) + ch.srv.Log().Debug("Unable to enable plugin installed from feature flag.", mlog.String("plugin_id", pluginID), mlog.Err(err), mlog.String("version", version)) } else { - ch.srv.Log.Debug("Installed and enabled plugin.", mlog.String("plugin_id", pluginID), mlog.String("version", version)) + ch.srv.Log().Debug("Installed and enabled plugin.", mlog.String("plugin_id", pluginID), mlog.String("version", version)) } } } diff --git a/app/post_metadata_test.go b/app/post_metadata_test.go index 63ee5c99d6..396aaa350a 100644 --- a/app/post_metadata_test.go +++ b/app/post_metadata_test.go @@ -796,7 +796,7 @@ func TestPreparePostForClientWithImageProxy(t *testing.T) { *cfg.ImageProxySettings.RemoteImageProxyOptions = "foo" }) - th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log) + th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log()) return th } diff --git a/app/post_test.go b/app/post_test.go index 2ca888c004..800511abf9 100644 --- a/app/post_test.go +++ b/app/post_test.go @@ -472,7 +472,7 @@ func TestImageProxy(t *testing.T) { *cfg.ServiceSettings.SiteURL = "http://mymattermost.com" }) - th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log) + th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log()) for name, tc := range map[string]struct { ProxyType string @@ -686,7 +686,7 @@ func TestCreatePost(t *testing.T) { *cfg.ImageProxySettings.RemoteImageProxyOptions = "foo" }) - th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log) + th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log()) imageURL := "http://mydomain.com/myimage" proxiedImageURL := "http://mymattermost.com/api/v4/image?url=http%3A%2F%2Fmydomain.com%2Fmyimage" @@ -956,7 +956,7 @@ func TestPatchPost(t *testing.T) { *cfg.ImageProxySettings.RemoteImageProxyOptions = "foo" }) - th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log) + th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log()) imageURL := "http://mydomain.com/myimage" proxiedImageURL := "http://mymattermost.com/api/v4/image?url=http%3A%2F%2Fmydomain.com%2Fmyimage" @@ -1252,7 +1252,7 @@ func TestUpdatePost(t *testing.T) { *cfg.ImageProxySettings.RemoteImageProxyOptions = "foo" }) - th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log) + th.App.ch.imageProxy = imageproxy.MakeImageProxy(th.Server.platform, th.Server.HTTPService(), th.Server.Log()) imageURL := "http://mydomain.com/myimage" proxiedImageURL := "http://mymattermost.com/api/v4/image?url=http%3A%2F%2Fmydomain.com%2Fmyimage" diff --git a/app/security_update_check.go b/app/security_update_check.go index 258ef03f0e..ecbf2f03d0 100644 --- a/app/security_update_check.go +++ b/app/security_update_check.go @@ -91,7 +91,7 @@ func (s *Server) DoSecurityUpdateCheck() { var bulletins model.SecurityBulletins if jsonErr := json.NewDecoder(res.Body).Decode(&bulletins); jsonErr != nil { - s.Log.Error("Failed to decode JSON", mlog.Err(jsonErr)) + s.Log().Error("Failed to decode JSON", mlog.Err(jsonErr)) return } diff --git a/app/server.go b/app/server.go index bcb0e63c97..17dcfdcba0 100644 --- a/app/server.go +++ b/app/server.go @@ -181,9 +181,7 @@ type Server struct { phase2PermissionsMigrationComplete bool - Audit *audit.Audit - Log *mlog.Logger - NotificationsLog *mlog.Logger + Audit *audit.Audit joinCluster bool startMetrics bool @@ -243,7 +241,6 @@ func NewServer(options ...Option) (*Server, error) { platformCfg := platform.ServiceConfig{ ConfigStore: configStore, - Logger: s.Log, StartMetrics: s.startMetrics, Cluster: s.Cluster, } @@ -262,11 +259,6 @@ func NewServer(options ...Option) (*Server, error) { } } - // Step 2: Logging - if err := s.initLogging(); err != nil { - mlog.Error("Could not initiate logging", mlog.Err(err)) - } - subpath, err := utils.GetSubpathFromConfig(s.platform.Config()) if err != nil { return nil, errors.Wrap(err, "failed to parse SiteURL subpath") @@ -412,7 +404,7 @@ func NewServer(options ...Option) (*Server, error) { FileInfoStoreKey: &fileInfoWrapper{srv: s}, ClusterKey: s.clusterWrapper, UserKey: New(ServerConnector(s.Channels())), - LogKey: s.GetLogger(), + LogKey: s.Log(), CloudKey: &cloudWrapper{cloud: s.Cloud}, KVStoreKey: &kvStoreWrapper{srv: s}, StoreKey: store.NewStoreServiceAdapter(s.Store), @@ -490,7 +482,7 @@ func NewServer(options ...Option) (*Server, error) { return nil, errors.Wrap(err, "Unable to create opengraphdata cache") } - s.createPushNotificationsHub(request.EmptyContext(s.GetLogger())) + s.createPushNotificationsHub(request.EmptyContext(s.Log())) if err2 := i18n.InitTranslations(*s.platform.Config().LocalizationSettings.DefaultServerLocale, *s.platform.Config().LocalizationSettings.DefaultClientLocale); err2 != nil { return nil, errors.Wrapf(err2, "unable to load Mattermost translation files") @@ -523,7 +515,7 @@ func NewServer(options ...Option) (*Server, error) { s.Publish(message) }) - if err = s.initLogging(); err != nil { + if err = s.platform.ReconfigureLogger(); err != nil { mlog.Error("Error re-configuring logging after config change", mlog.Err(err)) return } @@ -539,7 +531,7 @@ func NewServer(options ...Option) (*Server, error) { }) - s.telemetryService = telemetry.New(New(ServerConnector(s.Channels())), s.Store, s.SearchEngine, s.Log) + s.telemetryService = telemetry.New(New(ServerConnector(s.Channels())), s.Store, s.SearchEngine, s.Log()) s.platform.SetTelemetryId(s.TelemetryId()) // TODO: move this into platform once telemetry service moved to platform. emailService, err := email.NewService(email.ServiceConfig{ @@ -613,12 +605,12 @@ func NewServer(options ...Option) (*Server, error) { } } - s.removeUnlicensedLogTargets(license) - s.enableLoggingMetrics() + s.platform.RemoveUnlicensedLogTargets(license) + s.platform.EnableLoggingMetrics() s.loggerLicenseListenerId = s.AddLicenseListener(func(oldLicense, newLicense *model.License) { - s.removeUnlicensedLogTargets(newLicense) - s.enableLoggingMetrics() + s.platform.RemoveUnlicensedLogTargets(newLicense) + s.platform.EnableLoggingMetrics() }) // Enable developer settings if this is a "dev" build @@ -642,7 +634,7 @@ func NewServer(options ...Option) (*Server, error) { } if err := s.platform.RestartMetrics(); err != nil { - s.Log.Error("Failed to reset metrics server", mlog.Err(err)) + s.Log().Error("Failed to reset metrics server", mlog.Err(err)) } }) @@ -668,7 +660,7 @@ func NewServer(options ...Option) (*Server, error) { s.platform.AddConfigListener(func(old, new *model.Config) { appInstance := New(ServerConnector(s.Channels())) if *old.GuestAccountsSettings.Enable && !*new.GuestAccountsSettings.Enable { - c := request.EmptyContext(s.GetLogger()) + c := request.EmptyContext(s.Log()) if appErr := appInstance.DeactivateGuests(c); appErr != nil { mlog.Error("Unable to deactivate guest accounts", mlog.Err(appErr)) } @@ -678,7 +670,7 @@ func NewServer(options ...Option) (*Server, error) { // Disable active guest accounts on first run if guest accounts are disabled if !*s.platform.Config().GuestAccountsSettings.Enable { appInstance := New(ServerConnector(s.Channels())) - c := request.EmptyContext(s.GetLogger()) + c := request.EmptyContext(s.Log()) if appErr := appInstance.DeactivateGuests(c); appErr != nil { mlog.Error("Unable to deactivate guest accounts", mlog.Err(appErr)) } @@ -786,70 +778,6 @@ func (s *Server) DatabaseTypeAndSchemaVersion() (string, string) { return *s.platform.Config().SqlSettings.DriverName, strconv.Itoa(schemaVersion) } -// initLogging initializes and configures the logger(s). This may be called more than once. -func (s *Server) initLogging() error { - var err error - // create the app logger if needed - if s.Log == nil { - s.Log, err = mlog.NewLogger() - if err != nil { - return err - } - } - - // create notification logger if needed - if s.NotificationsLog == nil { - l, err := mlog.NewLogger() - if err != nil { - return err - } - s.NotificationsLog = l.With(mlog.String("logSource", "notifications")) - } - - if err := s.platform.ConfigureLogger("logging", s.Log, &s.platform.Config().LogSettings, config.GetLogFileLocation); err != nil { - // if the config is locked then a unit test has already configured and locked the logger; not an error. - if !errors.Is(err, mlog.ErrConfigurationLock) { - // revert to default logger if the config is invalid - mlog.InitGlobalLogger(nil) - return err - } - } - - // Redirect default Go logger to app logger. - s.Log.RedirectStdLog(mlog.LvlStdLog) - - // Use the app logger as the global logger (eventually remove all instances of global logging). - mlog.InitGlobalLogger(s.Log) - - notificationLogSettings := config.GetLogSettingsFromNotificationsLogSettings(&s.platform.Config().NotificationLogSettings) - if err := s.platform.ConfigureLogger("notification logging", s.NotificationsLog, notificationLogSettings, config.GetNotificationsLogFileLocation); err != nil { - if !errors.Is(err, mlog.ErrConfigurationLock) { - mlog.Error("Error configuring notification logger", mlog.Err(err)) - return err - } - } - return nil -} - -// removeUnlicensedLogTargets removes any unlicensed log target types. -func (s *Server) removeUnlicensedLogTargets(license *model.License) { - if license != nil && *license.Features.AdvancedLogging { - // advanced logging enabled via license; no need to remove any targets - return - } - - timeoutCtx, cancelCtx := context.WithTimeout(context.Background(), time.Second*10) - defer cancelCtx() - - s.Log.RemoveTargets(timeoutCtx, func(ti mlog.TargetInfo) bool { - return ti.Type != "*targets.Writer" && ti.Type != "*targets.File" - }) - - s.NotificationsLog.RemoveTargets(timeoutCtx, func(ti mlog.TargetInfo) bool { - return ti.Type != "*targets.Writer" && ti.Type != "*targets.File" - }) -} - func (s *Server) startInterClusterServices(license *model.License) error { if license == nil { mlog.Debug("No license provided; Remote Cluster services disabled") @@ -916,22 +844,6 @@ func (s *Server) startInterClusterServices(license *model.License) error { return nil } -func (s *Server) enableLoggingMetrics() { - if s.GetMetrics() == nil { - return - } - - s.Log.SetMetricsCollector(s.GetMetrics().GetLoggerMetricsCollector(), mlog.DefaultMetricsUpdateFreqMillis) - - // logging config needs to be reloaded when metrics collector is added or changed. - if err := s.initLogging(); err != nil { - mlog.Error("Error re-configuring logging for metrics") - return - } - - mlog.Debug("Logging metrics enabled") -} - const TimeToWaitForConnectionsToCloseOnServerShutdown = time.Second func (s *Server) StopHTTPServer() { @@ -957,7 +869,7 @@ func (s *Server) StopHTTPServer() { } func (s *Server) Shutdown() { - s.Log.Info("Stopping Server...") + s.Log().Info("Stopping Server...") defer sentry.Flush(2 * time.Second) @@ -968,24 +880,24 @@ func (s *Server) Shutdown() { if s.tracer != nil { if err := s.tracer.Close(); err != nil { - s.Log.Warn("Unable to cleanly shutdown opentracing client", mlog.Err(err)) + s.Log().Warn("Unable to cleanly shutdown opentracing client", mlog.Err(err)) } } err := s.telemetryService.Shutdown() if err != nil { - s.Log.Warn("Unable to cleanly shutdown telemetry client", mlog.Err(err)) + s.Log().Warn("Unable to cleanly shutdown telemetry client", mlog.Err(err)) } s.serviceMux.RLock() if s.sharedChannelService != nil { if err = s.sharedChannelService.Shutdown(); err != nil { - s.Log.Error("Error shutting down shared channel services", mlog.Err(err)) + s.Log().Error("Error shutting down shared channel services", mlog.Err(err)) } } if s.remoteClusterService != nil { if err = s.remoteClusterService.Shutdown(); err != nil { - s.Log.Error("Error shutting down intercluster services", mlog.Err(err)) + s.Log().Error("Error shutting down intercluster services", mlog.Err(err)) } } s.serviceMux.RUnlock() @@ -1007,7 +919,7 @@ func (s *Server) Shutdown() { s.platform.StopFeatureFlagUpdateJob() if err = s.platform.ShutdownConfig(); err != nil { - s.Log.Warn("Failed to shut down config store", mlog.Err(err)) + s.Log().Warn("Failed to shut down config store", mlog.Err(err)) } if s.Cluster != nil { @@ -1015,7 +927,7 @@ func (s *Server) Shutdown() { } if err = s.platform.ShutdownMetrics(); err != nil { - s.Log.Warn("Failed to stop metrics server", mlog.Err(err)) + s.Log().Warn("Failed to stop metrics server", mlog.Err(err)) } // This must be done after the cluster is stopped. @@ -1024,10 +936,10 @@ func (s *Server) Shutdown() { // before stopping them as both calls essentially become no-ops // if nothing is running. if err = s.Jobs.StopWorkers(); err != nil && !errors.Is(err, jobs.ErrWorkersNotRunning) { - s.Log.Warn("Failed to stop job server workers", mlog.Err(err)) + s.Log().Warn("Failed to stop job server workers", mlog.Err(err)) } if err = s.Jobs.StopSchedulers(); err != nil && !errors.Is(err, jobs.ErrSchedulersNotRunning) { - s.Log.Warn("Failed to stop job server schedulers", mlog.Err(err)) + s.Log().Warn("Failed to stop job server schedulers", mlog.Err(err)) } } @@ -1036,7 +948,7 @@ func (s *Server) Shutdown() { // on parent services. for name, product := range s.products { if err2 := product.Stop(); err2 != nil { - s.Log.Warn("Unable to cleanly stop product", mlog.String("name", name), mlog.Err(err2)) + s.Log().Warn("Unable to cleanly stop product", mlog.String("name", name), mlog.Err(err2)) } } @@ -1046,19 +958,19 @@ func (s *Server) Shutdown() { if s.CacheProvider != nil { if err = s.CacheProvider.Close(); err != nil { - s.Log.Warn("Unable to cleanly shutdown cache", mlog.Err(err)) + s.Log().Warn("Unable to cleanly shutdown cache", mlog.Err(err)) } } - s.Log.Info("Server stopped") + s.Log().Info("Server stopped") // shutdown main and notification loggers which will flush any remaining log records. timeoutCtx, timeoutCancel := context.WithTimeout(context.Background(), time.Second*15) defer timeoutCancel() - if err = s.NotificationsLog.ShutdownWithTimeout(timeoutCtx); err != nil { + if err = s.NotificationsLog().ShutdownWithTimeout(timeoutCtx); err != nil { fmt.Fprintf(os.Stderr, "Error shutting down notification logger: %v", err) } - if err = s.Log.ShutdownWithTimeout(timeoutCtx); err != nil { + if err = s.Log().ShutdownWithTimeout(timeoutCtx); err != nil { fmt.Fprintf(os.Stderr, "Error shutting down main logger: %v", err) } } @@ -1240,7 +1152,7 @@ func (s *Server) Start() error { // If we have debugging of CORS turned on then forward messages to logs if debug { - corsWrapper.Log = s.Log.With(mlog.String("source", "cors")).StdLogger(mlog.LvlDebug) + corsWrapper.Log = s.Log().With(mlog.String("source", "cors")).StdLogger(mlog.LvlDebug) } handler = corsWrapper.Handler(handler) @@ -1260,7 +1172,7 @@ func (s *Server) Start() error { s.Busy = NewBusy(s.Cluster) // Creating a logger for logging errors from http.Server at error level - errStdLog := s.Log.With(mlog.String("source", "httpserver")).StdLogger(mlog.LvlError) + errStdLog := s.Log().With(mlog.String("source", "httpserver")).StdLogger(mlog.LvlError) s.Server = &http.Server{ Handler: handler, @@ -1305,7 +1217,7 @@ func (s *Server) Start() error { server := &http.Server{ Addr: httpListenAddress, Handler: m.HTTPHandler(nil), - ErrorLog: s.Log.With(mlog.String("source", "le_forwarder_server")).StdLogger(mlog.LvlError), + ErrorLog: s.Log().With(mlog.String("source", "le_forwarder_server")).StdLogger(mlog.LvlError), } go server.ListenAndServe() } else { @@ -1319,7 +1231,7 @@ func (s *Server) Start() error { server := &http.Server{ Handler: http.HandlerFunc(handleHTTPRedirect), - ErrorLog: s.Log.With(mlog.String("source", "forwarder_server")).StdLogger(mlog.LvlError), + ErrorLog: s.Log().With(mlog.String("source", "forwarder_server")).StdLogger(mlog.LvlError), } server.Serve(redirectListener) }() @@ -1732,7 +1644,7 @@ func (s *Server) StartSearchEngine() (string, string) { if s.SearchEngine.ElasticsearchEngine != nil && s.SearchEngine.ElasticsearchEngine.IsActive() { s.Go(func() { if err := s.SearchEngine.ElasticsearchEngine.Start(); err != nil { - s.Log.Error(err.Error()) + s.Log().Error(err.Error()) } }) } @@ -1947,14 +1859,6 @@ func (s *Server) HTTPService() httpservice.HTTPService { return s.httpService } -func (s *Server) SetLog(l *mlog.Logger) { - s.Log = l -} - -func (s *Server) GetLogger() mlog.LoggerIFace { - return s.Log -} - // GetStore returns the server's Store. Exposing via a method // allows interfaces to be created with subsets of server APIs. func (s *Server) GetStore() store.Store { @@ -2118,3 +2022,11 @@ func (a *App) GetAppliedSchemaMigrations() ([]model.AppliedMigration, *model.App func (s *Server) Platform() *platform.PlatformService { return s.platform } + +func (s *Server) Log() *mlog.Logger { + return s.platform.Logger() +} + +func (s *Server) NotificationsLog() *mlog.Logger { + return s.platform.NotificationsLogger() +} diff --git a/app/server_test.go b/app/server_test.go index 496a10822b..e7d5aa1cab 100644 --- a/app/server_test.go +++ b/app/server_test.go @@ -405,12 +405,13 @@ func TestPanicLog(t *testing.T) { logger.LockConfiguration() // Creating a server with logger - s, err := NewServer(SetLogger(logger)) + s, err := NewServer() require.NoError(t, err) + s.Platform().SetLogger(logger) // Route for just panicking s.Router.HandleFunc("/panic", func(writer http.ResponseWriter, request *http.Request) { - s.Log.Info("inside panic handler") + s.Log().Info("inside panic handler") panic("log this panic") }) diff --git a/app/web_hub.go b/app/web_hub.go index a3dcf8d0cd..5591d06073 100644 --- a/app/web_hub.go +++ b/app/web_hub.go @@ -90,7 +90,7 @@ func (a *App) TotalWebsocketConnections() int { func (s *Server) HubStart() { // Total number of hubs is twice the number of CPUs. numberOfHubs := runtime.NumCPU() * 2 - s.Log.Info("Starting websocket hubs", mlog.Int("number_of_hubs", numberOfHubs)) + s.Log().Info("Starting websocket hubs", mlog.Int("number_of_hubs", numberOfHubs)) hubs := make([]*Hub, numberOfHubs) diff --git a/services/remotecluster/mocks_test.go b/services/remotecluster/mocks_test.go index f23dade315..16bfd7ed8f 100644 --- a/services/remotecluster/mocks_test.go +++ b/services/remotecluster/mocks_test.go @@ -38,7 +38,7 @@ func (ms *mockServer) GetMetrics() einterfaces.MetricsInterface { func (ms *mockServer) IsLeader() bool { return true } func (ms *mockServer) AddClusterLeaderChangedListener(listener func()) string { return model.NewId() } func (ms *mockServer) RemoveClusterLeaderChangedListener(id string) {} -func (ms *mockServer) GetLogger() mlog.LoggerIFace { +func (ms *mockServer) Log() *mlog.Logger { return ms.logger } func (ms *mockServer) GetStore() store.Store { diff --git a/services/remotecluster/ping.go b/services/remotecluster/ping.go index 5bc6751dd5..6487d14006 100644 --- a/services/remotecluster/ping.go +++ b/services/remotecluster/ping.go @@ -33,7 +33,7 @@ func (rcs *Service) pingGenerator(pingChan chan *model.RemoteCluster, done <-cha // get all remotes, including any previously offline. remotes, err := rcs.server.GetStore().RemoteCluster().GetAll(model.RemoteClusterQueryFilter{}) if err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Ping remote cluster failed (could not get list of remotes)", mlog.Err(err)) + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Ping remote cluster failed (could not get list of remotes)", mlog.Err(err)) select { case <-time.After(PingFreq): continue @@ -74,7 +74,7 @@ func (rcs *Service) pingEmitter(pingChan <-chan *model.RemoteCluster, done <-cha online := rc.IsOnline() if err := rcs.pingRemote(rc); err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceWarn, "Remote cluster ping failed", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceWarn, "Remote cluster ping failed", mlog.String("remote", rc.DisplayName), mlog.String("remoteId", rc.RemoteId), mlog.Err(err), @@ -114,7 +114,7 @@ func (rcs *Service) pingRemote(rc *model.RemoteCluster) error { } if err := rcs.server.GetStore().RemoteCluster().SetLastPingAt(rc.RemoteId); err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Failed to update LastPingAt for remote cluster", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Failed to update LastPingAt for remote cluster", mlog.String("remote", rc.DisplayName), mlog.String("remoteId", rc.RemoteId), mlog.Err(err), @@ -132,7 +132,7 @@ func (rcs *Service) pingRemote(rc *model.RemoteCluster) error { metrics.ObserveRemoteClusterClockSkew(rc.RemoteId, skew) } - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceDebug, "Remote cluster ping", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceDebug, "Remote cluster ping", mlog.String("remote", rc.DisplayName), mlog.String("remoteId", rc.RemoteId), mlog.Int64("SentAt", ping.SentAt), diff --git a/services/remotecluster/recv.go b/services/remotecluster/recv.go index 6c827afe52..6431161acb 100644 --- a/services/remotecluster/recv.go +++ b/services/remotecluster/recv.go @@ -32,7 +32,7 @@ func (rcs *Service) ReceiveIncomingMsg(rc *model.RemoteCluster, msg model.Remote for _, l := range listeners { if err := callback(l, msg, &rcSanitized, &response); err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Error from remote cluster message listener", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Error from remote cluster message listener", mlog.String("msgId", msg.Id), mlog.String("topic", msg.Topic), mlog.String("remote", rc.DisplayName), mlog.Err(err)) response.Status = ResponseStatusFail diff --git a/services/remotecluster/sendfile.go b/services/remotecluster/sendfile.go index 9bf224cbf6..3144b066e6 100644 --- a/services/remotecluster/sendfile.go +++ b/services/remotecluster/sendfile.go @@ -59,7 +59,7 @@ func (rcs *Service) sendFile(task sendFileTask) { var response Response if err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Remote Cluster send file failed", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Remote Cluster send file failed", mlog.String("remote", task.rc.DisplayName), mlog.String("uploadId", task.us.Id), mlog.Err(err), @@ -67,7 +67,7 @@ func (rcs *Service) sendFile(task sendFileTask) { response.Status = ResponseStatusFail response.Err = err.Error() } else { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceDebug, "Remote Cluster file sent successfully", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceDebug, "Remote Cluster file sent successfully", mlog.String("remote", task.rc.DisplayName), mlog.String("uploadId", task.us.Id), ) @@ -82,7 +82,7 @@ func (rcs *Service) sendFile(task sendFileTask) { } func (rcs *Service) sendFileToRemote(timeout time.Duration, task sendFileTask) (*model.FileInfo, error) { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceDebug, "sending file to remote...", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceDebug, "sending file to remote...", mlog.String("remote", task.rc.DisplayName), mlog.String("uploadId", task.us.Id), mlog.String("file_path", task.us.Path), diff --git a/services/remotecluster/sendmsg.go b/services/remotecluster/sendmsg.go index 78350a3e4a..9b1396c57e 100644 --- a/services/remotecluster/sendmsg.go +++ b/services/remotecluster/sendmsg.go @@ -99,7 +99,7 @@ func (rcs *Service) sendMsg(task sendMsgTask) { u, err := url.Parse(task.rc.SiteURL) if err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Invalid siteURL while sending message to remote", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Invalid siteURL while sending message to remote", mlog.String("remote", task.rc.DisplayName), mlog.String("msgId", task.msg.Id), mlog.Err(err), @@ -112,20 +112,20 @@ func (rcs *Service) sendMsg(task sendMsgTask) { respJSON, err := rcs.sendFrameToRemote(SendTimeout, task.rc, frame, u.String()) if err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Remote Cluster send message failed", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Remote Cluster send message failed", mlog.String("remote", task.rc.DisplayName), mlog.String("msgId", task.msg.Id), mlog.Err(err), ) errResp = err } else { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceDebug, "Remote Cluster message sent successfully", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceDebug, "Remote Cluster message sent successfully", mlog.String("remote", task.rc.DisplayName), mlog.String("msgId", task.msg.Id), ) if err = json.Unmarshal(respJSON, &response); err != nil { - rcs.server.GetLogger().Error("Invalid response sending message to remote cluster", + rcs.server.Log().Error("Invalid response sending message to remote cluster", mlog.String("remote", task.rc.DisplayName), mlog.Err(err), ) diff --git a/services/remotecluster/sendprofileImage.go b/services/remotecluster/sendprofileImage.go index e86adff2ba..1cac734ce3 100644 --- a/services/remotecluster/sendprofileImage.go +++ b/services/remotecluster/sendprofileImage.go @@ -57,7 +57,7 @@ func (rcs *Service) sendProfileImage(task sendProfileImageTask) { var response Response if err != nil { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceError, "Remote Cluster send profile image failed", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceError, "Remote Cluster send profile image failed", mlog.String("remote", task.rc.DisplayName), mlog.String("UserId", task.userID), mlog.Err(err), @@ -65,7 +65,7 @@ func (rcs *Service) sendProfileImage(task sendProfileImageTask) { response.Status = ResponseStatusFail response.Err = err.Error() } else { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceDebug, "Remote Cluster profile image sent successfully", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceDebug, "Remote Cluster profile image sent successfully", mlog.String("remote", task.rc.DisplayName), mlog.String("UserId", task.userID), ) @@ -79,7 +79,7 @@ func (rcs *Service) sendProfileImage(task sendProfileImageTask) { } func (rcs *Service) sendProfileImageToRemote(timeout time.Duration, task sendProfileImageTask) error { - rcs.server.GetLogger().Log(mlog.LvlRemoteClusterServiceDebug, "sending profile image to remote...", + rcs.server.Log().Log(mlog.LvlRemoteClusterServiceDebug, "sending profile image to remote...", mlog.String("remote", task.rc.DisplayName), mlog.String("UserId", task.userID), ) diff --git a/services/remotecluster/service.go b/services/remotecluster/service.go index e9eb8918c6..7d7945dff4 100644 --- a/services/remotecluster/service.go +++ b/services/remotecluster/service.go @@ -46,7 +46,7 @@ type ServerIface interface { AddClusterLeaderChangedListener(listener func()) string RemoveClusterLeaderChangedListener(id string) GetStore() store.Store - GetLogger() mlog.LoggerIFace + Log() *mlog.Logger GetMetrics() einterfaces.MetricsInterface } @@ -244,7 +244,7 @@ func (rcs *Service) resume() { go rcs.sendLoop(i, rcs.done) } - rcs.server.GetLogger().Debug("Remote Cluster Service active") + rcs.server.Log().Debug("Remote Cluster Service active") } func (rcs *Service) pause() { @@ -258,5 +258,5 @@ func (rcs *Service) pause() { close(rcs.done) rcs.done = nil - rcs.server.GetLogger().Debug("Remote Cluster Service inactive") + rcs.server.Log().Debug("Remote Cluster Service inactive") } diff --git a/services/sharedchannel/attachment.go b/services/sharedchannel/attachment.go index 6b40dd7e1e..e1dd4e0c9a 100644 --- a/services/sharedchannel/attachment.go +++ b/services/sharedchannel/attachment.go @@ -21,7 +21,7 @@ func (scs *Service) shouldSyncAttachment(fi *model.FileInfo, rc *model.RemoteClu sca, err := scs.server.GetStore().SharedChannel().GetAttachment(fi.Id, rc.RemoteId) if err != nil { if _, ok := err.(errNotFound); !ok { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "error fetching shared channel attachment", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "error fetching shared channel attachment", mlog.String("file_id", fi.Id), mlog.String("remote_id", rc.RemoteId), mlog.Err(err), @@ -100,7 +100,7 @@ func (scs *Service) sendAttachmentForRemote(fi *model.FileInfo, post *model.Post } if !resp.IsSuccess() { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "send file failed", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "send file failed", mlog.String("remote", rc.DisplayName), mlog.String("uploadId", usResp.Id), mlog.String("err", resp.Err), @@ -111,7 +111,7 @@ func (scs *Service) sendAttachmentForRemote(fi *model.FileInfo, post *model.Post // response payload should be a model.FileInfo. var fi model.FileInfo if err2 := json.Unmarshal(resp.Payload, &fi); err2 != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "invalid file info response after send file", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "invalid file info response after send file", mlog.String("remote", rc.DisplayName), mlog.String("uploadId", usResp.Id), mlog.Err(err2), @@ -125,7 +125,7 @@ func (scs *Service) sendAttachmentForRemote(fi *model.FileInfo, post *model.Post RemoteId: rc.RemoteId, } if _, err2 := scs.server.GetStore().SharedChannel().UpsertAttachment(sca); err2 != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "error saving SharedChannelAttachment", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "error saving SharedChannelAttachment", mlog.String("remote", rc.DisplayName), mlog.String("uploadId", usResp.Id), mlog.Err(err2), @@ -133,7 +133,7 @@ func (scs *Service) sendAttachmentForRemote(fi *model.FileInfo, post *model.Post return } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "send file successful", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "send file successful", mlog.String("remote", rc.DisplayName), mlog.String("uploadId", usResp.Id), ) @@ -157,7 +157,7 @@ func (scs *Service) onReceiveUploadCreate(msg model.RemoteClusterMsg, rc *model. us.RemoteId = rc.RemoteId // don't let remotes try to impersonate each other // create upload session. - usSaved, appErr := scs.app.CreateUploadSession(request.EmptyContext(scs.server.GetLogger()), &us) + usSaved, appErr := scs.app.CreateUploadSession(request.EmptyContext(scs.server.Log()), &us) if appErr != nil { return appErr } diff --git a/services/sharedchannel/channelinvite.go b/services/sharedchannel/channelinvite.go index 5c204c3d6a..0bf1677dd4 100644 --- a/services/sharedchannel/channelinvite.go +++ b/services/sharedchannel/channelinvite.go @@ -122,7 +122,7 @@ func (scs *Service) onReceiveChannelInvite(msg model.RemoteClusterMsg, rc *model return fmt.Errorf("invalid channel invite: %w", err) } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Channel invite received", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Channel invite received", mlog.String("remote", rc.DisplayName), mlog.String("channel_id", invite.ChannelId), mlog.String("channel_name", invite.Name), @@ -158,7 +158,7 @@ func (scs *Service) onReceiveChannelInvite(msg model.RemoteClusterMsg, rc *model } if _, err := scs.server.GetStore().SharedChannel().Save(sharedChannel); err != nil { - scs.app.PermanentDeleteChannel(request.EmptyContext(scs.server.GetLogger()), channel) + scs.app.PermanentDeleteChannel(request.EmptyContext(scs.server.Log()), channel) return fmt.Errorf("cannot create shared channel (channel_id=%s): %w", invite.ChannelId, err) } @@ -172,7 +172,7 @@ func (scs *Service) onReceiveChannelInvite(msg model.RemoteClusterMsg, rc *model } if _, err := scs.server.GetStore().SharedChannel().SaveRemote(sharedChannelRemote); err != nil { - scs.app.PermanentDeleteChannel(request.EmptyContext(scs.server.GetLogger()), channel) + scs.app.PermanentDeleteChannel(request.EmptyContext(scs.server.Log()), channel) scs.server.GetStore().SharedChannel().Delete(sharedChannel.ChannelId) return fmt.Errorf("cannot create shared channel remote (channel_id=%s): %w", invite.ChannelId, err) } @@ -197,7 +197,7 @@ func (scs *Service) handleChannelCreation(invite channelInviteMsg, rc *model.Rem } // check user perms? - channel, appErr := scs.app.CreateChannelWithUser(request.EmptyContext(scs.server.GetLogger()), channelNew, rc.CreatorId) + channel, appErr := scs.app.CreateChannelWithUser(request.EmptyContext(scs.server.Log()), channelNew, rc.CreatorId) if appErr != nil { return nil, fmt.Errorf("cannot create channel `%s`: %w", invite.ChannelId, appErr) } @@ -210,7 +210,7 @@ func (scs *Service) createDirectChannel(invite channelInviteMsg) (*model.Channel return nil, fmt.Errorf("cannot create direct channel `%s` insufficient participant count `%d`", invite.ChannelId, len(invite.DirectParticipantIDs)) } - channel, err := scs.app.GetOrCreateDirectChannel(request.EmptyContext(scs.server.GetLogger()), invite.DirectParticipantIDs[0], invite.DirectParticipantIDs[1], model.WithID(invite.ChannelId)) + channel, err := scs.app.GetOrCreateDirectChannel(request.EmptyContext(scs.server.Log()), invite.DirectParticipantIDs[0], invite.DirectParticipantIDs[1], model.WithID(invite.ChannelId)) if err != nil { return nil, fmt.Errorf("cannot create direct channel `%s`: %w", invite.ChannelId, err) } diff --git a/services/sharedchannel/channelinvite_test.go b/services/sharedchannel/channelinvite_test.go index 485cc3ac54..4ea344b21d 100644 --- a/services/sharedchannel/channelinvite_test.go +++ b/services/sharedchannel/channelinvite_test.go @@ -19,17 +19,12 @@ import ( "github.com/mattermost/mattermost-server/v6/store/storetest/mocks" ) -type mockLogger struct { - mlog.LoggerIFace -} - -func (ml *mockLogger) Log(level mlog.Level, s string, flds ...mlog.Field) {} - func TestOnReceiveChannelInvite(t *testing.T) { t.Run("when msg payload is empty, it does nothing", func(t *testing.T) { mockServer := &MockServerIface{} - mockLogger := &mockLogger{} - mockServer.On("GetLogger").Return(mockLogger) + mockLogger, err := mlog.NewLogger() + require.NoError(t, err) + mockServer.On("Log").Return(mockLogger) mockApp := &MockAppIface{} scs := &Service{ server: mockServer, @@ -43,15 +38,16 @@ func TestOnReceiveChannelInvite(t *testing.T) { remoteCluster := &model.RemoteCluster{} msg := model.RemoteClusterMsg{} - err := scs.onReceiveChannelInvite(msg, remoteCluster, nil) + err = scs.onReceiveChannelInvite(msg, remoteCluster, nil) require.NoError(t, err) mockStore.AssertNotCalled(t, "Channel") }) t.Run("when invitation prescribes a readonly channel, it does create a readonly channel", func(t *testing.T) { mockServer := &MockServerIface{} - mockLogger := &mockLogger{} - mockServer.On("GetLogger").Return(mockLogger) + mockLogger, err := mlog.NewLogger() + require.NoError(t, err) + mockServer.On("Log").Return(mockLogger) mockApp := &MockAppIface{} scs := &Service{ server: mockServer, @@ -110,8 +106,9 @@ func TestOnReceiveChannelInvite(t *testing.T) { t.Run("when invitation prescribes a readonly channel and readonly update fails, it returns an error", func(t *testing.T) { mockServer := &MockServerIface{} - mockLogger := &mockLogger{} - mockServer.On("GetLogger").Return(mockLogger) + mockLogger, err := mlog.NewLogger() + require.NoError(t, err) + mockServer.On("Log").Return(mockLogger) mockApp := &MockAppIface{} scs := &Service{ server: mockServer, @@ -152,8 +149,9 @@ func TestOnReceiveChannelInvite(t *testing.T) { t.Run("when invitation prescribes a direct channel, it does create a direct channel", func(t *testing.T) { mockServer := &MockServerIface{} - mockLogger := &mockLogger{} - mockServer.On("GetLogger").Return(mockLogger) + mockLogger, err := mlog.NewLogger() + require.NoError(t, err) + mockServer.On("Log").Return(mockLogger) mockApp := &MockAppIface{} scs := &Service{ server: mockServer, diff --git a/services/sharedchannel/mock_ServerIface_test.go b/services/sharedchannel/mock_ServerIface_test.go index 233f33db7f..24c8bc064f 100644 --- a/services/sharedchannel/mock_ServerIface_test.go +++ b/services/sharedchannel/mock_ServerIface_test.go @@ -50,22 +50,6 @@ func (_m *MockServerIface) Config() *model.Config { return r0 } -// GetLogger provides a mock function with given fields: -func (_m *MockServerIface) GetLogger() mlog.LoggerIFace { - ret := _m.Called() - - var r0 mlog.LoggerIFace - if rf, ok := ret.Get(0).(func() mlog.LoggerIFace); ok { - r0 = rf() - } else { - if ret.Get(0) != nil { - r0 = ret.Get(0).(mlog.LoggerIFace) - } - } - - return r0 -} - // GetRemoteClusterService provides a mock function with given fields: func (_m *MockServerIface) GetRemoteClusterService() remotecluster.RemoteClusterServiceIFace { ret := _m.Called() @@ -112,6 +96,22 @@ func (_m *MockServerIface) IsLeader() bool { return r0 } +// Log provides a mock function with given fields: +func (_m *MockServerIface) Log() *mlog.Logger { + ret := _m.Called() + + var r0 *mlog.Logger + if rf, ok := ret.Get(0).(func() *mlog.Logger); ok { + r0 = rf() + } else { + if ret.Get(0) != nil { + r0 = ret.Get(0).(*mlog.Logger) + } + } + + return r0 +} + // RemoveClusterLeaderChangedListener provides a mock function with given fields: id func (_m *MockServerIface) RemoveClusterLeaderChangedListener(id string) { _m.Called(id) diff --git a/services/sharedchannel/permalink.go b/services/sharedchannel/permalink.go index 8a81c87a82..003b55c4fd 100644 --- a/services/sharedchannel/permalink.go +++ b/services/sharedchannel/permalink.go @@ -36,11 +36,11 @@ func (scs *Service) processPermalinkToRemote(p *model.Post) string { } postList, err := scs.server.GetStore().Post().Get(context.Background(), postID, opts, "", map[string]bool{}) if err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceWarn, "Unable to get post during replacing permalinks", mlog.Err(err)) + scs.server.Log().Log(mlog.LvlSharedChannelServiceWarn, "Unable to get post during replacing permalinks", mlog.Err(err)) return msg } if len(postList.Order) == 0 { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceWarn, "No post found for permalink", mlog.String("postID", postID)) + scs.server.Log().Log(mlog.LvlSharedChannelServiceWarn, "No post found for permalink", mlog.String("postID", postID)) return msg } @@ -66,7 +66,7 @@ func (scs *Service) processPermalinkFromRemote(p *model.Post, team *model.Team) // Extract host name parsed, err := url.Parse(remoteLink) if err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceWarn, "Unable to parse the remote link during replacing permalinks", mlog.Err(err)) + scs.server.Log().Log(mlog.LvlSharedChannelServiceWarn, "Unable to parse the remote link during replacing permalinks", mlog.Err(err)) return remoteLink } diff --git a/services/sharedchannel/permalink_test.go b/services/sharedchannel/permalink_test.go index 05b1789b2f..f6c9cf35d0 100644 --- a/services/sharedchannel/permalink_test.go +++ b/services/sharedchannel/permalink_test.go @@ -34,7 +34,7 @@ func TestProcessPermalinkToRemote(t *testing.T) { mockServer := scs.server.(*MockServerIface) mockServer.On("GetStore").Return(mockStore) - mockServer.On("GetLogger").Return(mlog.NewLogger()) + mockServer.On("Log").Return(mlog.NewLogger()) mockApp := scs.app.(*MockAppIface) mockApp.On("SendEphemeralPost", mock.Anything, "user", mock.AnythingOfType("*model.Post")).Return(&model.Post{}).Times(1) diff --git a/services/sharedchannel/service.go b/services/sharedchannel/service.go index f73b0350b7..0acdc5e9df 100644 --- a/services/sharedchannel/service.go +++ b/services/sharedchannel/service.go @@ -40,7 +40,7 @@ type ServerIface interface { AddClusterLeaderChangedListener(listener func()) string RemoveClusterLeaderChangedListener(id string) GetStore() store.Store - GetLogger() mlog.LoggerIFace + Log() *mlog.Logger GetRemoteClusterService() remotecluster.RemoteClusterServiceIFace } @@ -166,7 +166,7 @@ func (scs *Service) sendEphemeralPost(channelId string, userId string, text stri Message: text, CreateAt: model.GetMillis(), } - scs.app.SendEphemeralPost(request.EmptyContext(scs.server.GetLogger()), userId, ephemeral) + scs.app.SendEphemeralPost(request.EmptyContext(scs.server.Log()), userId, ephemeral) } // onClusterLeaderChange is called whenever the cluster leader may have changed. @@ -191,7 +191,7 @@ func (scs *Service) resume() { go scs.syncLoop(scs.done) - scs.server.GetLogger().Debug("Shared Channel Service active") + scs.server.Log().Debug("Shared Channel Service active") } func (scs *Service) pause() { @@ -206,7 +206,7 @@ func (scs *Service) pause() { close(scs.done) scs.done = nil - scs.server.GetLogger().Debug("Shared Channel Service inactive") + scs.server.Log().Debug("Shared Channel Service inactive") } // Makes the remote channel to be read-only(announcement mode, only admins can create posts and reactions). @@ -229,7 +229,7 @@ func (scs *Service) makeChannelReadOnly(channel *model.Channel) *model.AppError }, } - _, err := scs.app.PatchChannelModerationsForChannel(request.EmptyContext(scs.server.GetLogger()), channel, readonlyChannelModerations) + _, err := scs.app.PatchChannelModerationsForChannel(request.EmptyContext(scs.server.Log()), channel, readonlyChannelModerations) return err } @@ -241,7 +241,7 @@ func (scs *Service) onConnectionStateChange(rc *model.RemoteCluster, online bool scs.ForceSyncForRemote(rc) } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Remote cluster connection status changed", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Remote cluster connection status changed", mlog.String("remote", rc.DisplayName), mlog.String("remoteId", rc.RemoteId), mlog.Bool("online", online), diff --git a/services/sharedchannel/sync_recv.go b/services/sharedchannel/sync_recv.go index 1e1fefae7f..1fb7b0663b 100644 --- a/services/sharedchannel/sync_recv.go +++ b/services/sharedchannel/sync_recv.go @@ -26,8 +26,8 @@ func (scs *Service) onReceiveSyncMessage(msg model.RemoteClusterMsg, rc *model.R return errors.New("empty sync message") } - if scs.server.GetLogger().IsLevelEnabled(mlog.LvlSharedChannelServiceMessagesInbound) { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceMessagesInbound, "inbound message", + if scs.server.Log().IsLevelEnabled(mlog.LvlSharedChannelServiceMessagesInbound) { + scs.server.Log().Log(mlog.LvlSharedChannelServiceMessagesInbound, "inbound message", mlog.String("remote", rc.DisplayName), mlog.String("msg", string(msg.Payload)), ) @@ -38,7 +38,7 @@ func (scs *Service) onReceiveSyncMessage(msg model.RemoteClusterMsg, rc *model.R if err := json.Unmarshal(msg.Payload, &sm); err != nil { return fmt.Errorf("invalid sync message: %w", err) } - return scs.processSyncMessage(request.EmptyContext(scs.server.GetLogger()), &sm, rc, response) + return scs.processSyncMessage(request.EmptyContext(scs.server.Log()), &sm, rc, response) } func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *model.RemoteCluster, response *remotecluster.Response) error { @@ -53,7 +53,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode ReactionErrors: make([]string, 0), } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Sync msg received", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Sync msg received", mlog.String("remote", rc.Name), mlog.String("channel_id", syncMsg.ChannelId), mlog.Int("user_count", len(syncMsg.Users)), @@ -69,7 +69,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode // add/update users before posts for _, user := range syncMsg.Users { if userSaved, err := scs.upsertSyncUser(c, user, channel, rc); err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error upserting sync user", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error upserting sync user", mlog.String("remote", rc.Name), mlog.String("channel_id", syncMsg.ChannelId), mlog.String("user_id", user.Id), @@ -79,7 +79,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode if syncResp.UsersLastUpdateAt < user.UpdateAt { syncResp.UsersLastUpdateAt = user.UpdateAt } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "User upserted via sync", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "User upserted via sync", mlog.String("remote", rc.Name), mlog.String("channel_id", syncMsg.ChannelId), mlog.String("user_id", user.Id), @@ -89,7 +89,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode for _, post := range syncMsg.Posts { if syncMsg.ChannelId != post.ChannelId { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "ChannelId mismatch", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "ChannelId mismatch", mlog.String("remote", rc.Name), mlog.String("sm.ChannelId", syncMsg.ChannelId), mlog.String("sm.Post.ChannelId", post.ChannelId), @@ -103,7 +103,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode var err2 error team, err2 = scs.server.GetStore().Channel().GetTeamForChannel(syncMsg.ChannelId) if err2 != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error getting Team for Channel", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error getting Team for Channel", mlog.String("ChannelId", post.ChannelId), mlog.String("PostId", post.Id), mlog.String("remote", rc.Name), @@ -123,7 +123,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode rpost, err := scs.upsertSyncPost(post, channel, rc) if err != nil { syncResp.PostErrors = append(syncResp.PostErrors, post.Id) - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error upserting sync post", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error upserting sync post", mlog.String("post_id", post.Id), mlog.String("channel_id", post.ChannelId), mlog.String("remote", rc.Name), @@ -137,7 +137,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode // add/remove reactions for _, reaction := range syncMsg.Reactions { if _, err := scs.upsertSyncReaction(reaction, rc); err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error upserting sync reaction", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error upserting sync reaction", mlog.String("remote", rc.Name), mlog.String("user_id", reaction.UserId), mlog.String("post_id", reaction.PostId), @@ -146,7 +146,7 @@ func (scs *Service) processSyncMessage(c request.CTX, syncMsg *syncMsg, rc *mode mlog.Err(err), ) } else { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Reaction upserted via sync", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Reaction upserted via sync", mlog.String("remote", rc.Name), mlog.String("user_id", reaction.UserId), mlog.String("post_id", reaction.PostId), @@ -208,7 +208,7 @@ func (scs *Service) upsertSyncUser(c request.CTX, user *model.User, channel *mod // Instead of undoing what succeeded on any failure we simply do all steps each // time. AddUserToChannel & AddUserToTeamByTeamId do not error if user was already // added and exit quickly. - if err := scs.app.AddUserToTeamByTeamId(request.EmptyContext(scs.server.GetLogger()), channel.TeamId, userSaved); err != nil { + if err := scs.app.AddUserToTeamByTeamId(request.EmptyContext(scs.server.Log()), channel.TeamId, userSaved); err != nil { return nil, fmt.Errorf("error adding sync user to Team: %w", err) } @@ -255,7 +255,7 @@ func (scs *Service) insertSyncUser(user *model.User, channel *model.Channel, rc _, field, value := e.InvalidInputInfo() if field == "email" || field == "username" { // username or email collision; try again with different suffix - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceWarn, "Collision inserting sync user", + scs.server.Log().Log(mlog.LvlSharedChannelServiceWarn, "Collision inserting sync user", mlog.String("field", field), mlog.Any("value", value), mlog.Int("attempt", i), @@ -309,7 +309,7 @@ func (scs *Service) updateSyncUser(patch *model.UserPatch, user *model.User, cha _, field, value := e.InvalidInputInfo() if field == "email" || field == "username" { // username or email collision; try again with different suffix - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceWarn, "Collision updating sync user", + scs.server.Log().Log(mlog.LvlSharedChannelServiceWarn, "Collision updating sync user", mlog.String("field", field), mlog.Any("value", value), mlog.Int("attempt", i), @@ -339,34 +339,34 @@ func (scs *Service) upsertSyncPost(post *model.Post, channel *model.Channel, rc if rpost == nil { // post doesn't exist; create new one - rpost, appErr = scs.app.CreatePost(request.EmptyContext(scs.server.GetLogger()), post, channel, true, true) + rpost, appErr = scs.app.CreatePost(request.EmptyContext(scs.server.Log()), post, channel, true, true) if appErr == nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Created sync post", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Created sync post", mlog.String("post_id", post.Id), mlog.String("channel_id", post.ChannelId), ) } } else if post.DeleteAt > 0 { // delete post - rpost, appErr = scs.app.DeletePost(request.EmptyContext(scs.server.GetLogger()), post.Id, post.UserId) + rpost, appErr = scs.app.DeletePost(request.EmptyContext(scs.server.Log()), post.Id, post.UserId) if appErr == nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Deleted sync post", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Deleted sync post", mlog.String("post_id", post.Id), mlog.String("channel_id", post.ChannelId), ) } } else if post.EditAt > rpost.EditAt || post.Message != rpost.Message { // update post - rpost, appErr = scs.app.UpdatePost(request.EmptyContext(scs.server.GetLogger()), post, false) + rpost, appErr = scs.app.UpdatePost(request.EmptyContext(scs.server.Log()), post, false) if appErr == nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Updated sync post", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Updated sync post", mlog.String("post_id", post.Id), mlog.String("channel_id", post.ChannelId), ) } } else { // nothing to update - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Update to sync post ignored", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Update to sync post ignored", mlog.String("post_id", post.Id), mlog.String("channel_id", post.ChannelId), ) @@ -386,9 +386,9 @@ func (scs *Service) upsertSyncReaction(reaction *model.Reaction, rc *model.Remot reaction.RemoteId = model.NewString(rc.RemoteId) if reaction.DeleteAt == 0 { - savedReaction, appErr = scs.app.SaveReactionForPost(request.EmptyContext(scs.server.GetLogger()), reaction) + savedReaction, appErr = scs.app.SaveReactionForPost(request.EmptyContext(scs.server.Log()), reaction) } else { - appErr = scs.app.DeleteReactionForPost(request.EmptyContext(scs.server.GetLogger()), reaction) + appErr = scs.app.DeleteReactionForPost(request.EmptyContext(scs.server.Log()), reaction) } var err error diff --git a/services/sharedchannel/sync_send.go b/services/sharedchannel/sync_send.go index a4ce41821a..90baee2134 100644 --- a/services/sharedchannel/sync_send.go +++ b/services/sharedchannel/sync_send.go @@ -67,7 +67,7 @@ func (scs *Service) NotifyUserProfileChanged(userID string) { scusers, err := scs.server.GetStore().SharedChannel().GetUsersForUser(userID) if err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Failed to fetch shared channel users", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Failed to fetch shared channel users", mlog.String("userID", userID), mlog.Err(err), ) @@ -106,7 +106,7 @@ func (scs *Service) ForceSyncForRemote(rc *model.RemoteCluster) { } scrs, err := scs.server.GetStore().SharedChannel().GetRemotes(opts) if err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Failed to fetch shared channel remotes", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Failed to fetch shared channel remotes", mlog.String("remote", rc.DisplayName), mlog.String("remoteId", rc.RemoteId), mlog.Err(err), @@ -189,7 +189,7 @@ func (scs *Service) doSync() time.Duration { if task.incRetry() { scs.addTask(task) } else { - scs.server.GetLogger().Error("Failed to synchronize shared channel", + scs.server.Log().Error("Failed to synchronize shared channel", mlog.String("channelId", task.channelID), mlog.String("remoteId", task.remoteID), mlog.Err(err), @@ -267,7 +267,7 @@ func (scs *Service) processTask(task syncTask) error { if rtask.incRetry() { scs.addTask(rtask) } else { - scs.server.GetLogger().Error("Failed to synchronize shared channel for remote cluster", + scs.server.Log().Error("Failed to synchronize shared channel for remote cluster", mlog.String("channelId", rtask.channelID), mlog.String("remote", rc.DisplayName), mlog.Err(err), @@ -284,7 +284,7 @@ func (scs *Service) handlePostError(postId string, task syncTask, rc *model.Remo if task.incRetry() { scs.addTask(task) } else { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "error syncing post", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "error syncing post", mlog.String("remote", rc.DisplayName), mlog.String("post_id", postId), ) @@ -295,7 +295,7 @@ func (scs *Service) handlePostError(postId string, task syncTask, rc *model.Remo // this post failed as part of a group of posts. Retry as an individual post. post, err := scs.server.GetStore().Post().GetSingle(postId, true) if err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "error fetching post for sync retry", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "error fetching post for sync retry", mlog.String("remote", rc.DisplayName), mlog.String("post_id", postId), ) @@ -331,7 +331,7 @@ func (scs *Service) notifyRemoteOffline(posts []*model.Post, rc *model.RemoteClu Message: T("sharedchannel.cannot_deliver_post", map[string]any{"Remote": rc.DisplayName}), CreateAt: post.CreateAt + 1, } - scs.app.SendEphemeralPost(request.EmptyContext(scs.server.GetLogger()), post.UserId, ephemeral) + scs.app.SendEphemeralPost(request.EmptyContext(scs.server.Log()), post.UserId, ephemeral) notified[post.UserId] = true } @@ -340,13 +340,13 @@ func (scs *Service) notifyRemoteOffline(posts []*model.Post, rc *model.RemoteClu func (scs *Service) updateCursorForRemote(scrId string, rc *model.RemoteCluster, cursor model.GetPostsSinceForSyncCursor) { if err := scs.server.GetStore().SharedChannel().UpdateRemoteCursor(scrId, cursor); err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "error updating cursor for shared channel remote", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "error updating cursor for shared channel remote", mlog.String("remote", rc.DisplayName), mlog.Err(err), ) return } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "updated cursor for remote", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "updated cursor for remote", mlog.String("remote_id", rc.RemoteId), mlog.String("remote", rc.DisplayName), mlog.Int64("last_post_update_at", cursor.LastPostUpdateAt), @@ -389,7 +389,7 @@ func (scs *Service) shouldUserSync(user *model.User, channelID string, rc *model ChannelId: channelID, } if _, err = scs.server.GetStore().SharedChannel().SaveUser(scu); err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error adding user to shared channel users", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error adding user to shared channel users", mlog.String("remote_id", rc.RemoteId), mlog.String("user_id", user.Id), mlog.String("channel_id", user.Id), @@ -413,13 +413,13 @@ func (scs *Service) syncProfileImage(user *model.User, channelID string, rc *mod rcs.SendProfileImage(ctx, user.Id, rc, scs.app, func(userId string, rc *model.RemoteCluster, resp *remotecluster.Response, err error) { if resp.IsSuccess() { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Users profile image synchronized", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Users profile image synchronized", mlog.String("remote_id", rc.RemoteId), mlog.String("user_id", user.Id), ) if err2 := scs.server.GetStore().SharedChannel().UpdateUserLastSyncAt(user.Id, channelID, rc.RemoteId); err2 != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error updating users LastSyncTime after profile image update", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error updating users LastSyncTime after profile image update", mlog.String("remote_id", rc.RemoteId), mlog.String("user_id", user.Id), mlog.Err(err2), @@ -428,7 +428,7 @@ func (scs *Service) syncProfileImage(user *model.User, channelID string, rc *mod return } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Error synchronizing users profile image", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Error synchronizing users profile image", mlog.String("remote_id", rc.RemoteId), mlog.String("user_id", user.Id), mlog.Err(err), diff --git a/services/sharedchannel/sync_send_remote.go b/services/sharedchannel/sync_send_remote.go index 010970fff1..8358982076 100644 --- a/services/sharedchannel/sync_send_remote.go +++ b/services/sharedchannel/sync_send_remote.go @@ -129,7 +129,7 @@ func (scs *Service) syncForRemote(task syncTask, rc *model.RemoteCluster) error } if sd.isEmpty() { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Not sending sync data; everything filtered out", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Not sending sync data; everything filtered out", mlog.String("remote", rc.DisplayName), mlog.String("channel_id", task.channelID), mlog.Bool("repeat", sd.resultRepeat), @@ -140,7 +140,7 @@ func (scs *Service) syncForRemote(task syncTask, rc *model.RemoteCluster) error return nil } - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceDebug, "Sending sync data", + scs.server.Log().Log(mlog.LvlSharedChannelServiceDebug, "Sending sync data", mlog.String("remote", rc.DisplayName), mlog.String("channel_id", task.channelID), mlog.Bool("repeat", sd.resultRepeat), @@ -272,7 +272,7 @@ func (scs *Service) fetchPostUsersForSync(sd *syncData) error { userIDs[post.UserId] = p2mm{} // get mentions and users for each mention - mentionMap := scs.app.MentionsToTeamMembers(request.EmptyContext(scs.server.GetLogger()), post.Message, sc.TeamId) + mentionMap := scs.app.MentionsToTeamMembers(request.EmptyContext(scs.server.Log()), post.Message, sc.TeamId) for _, userID := range mentionMap { userIDs[userID] = p2mm{ post: post, @@ -416,7 +416,7 @@ func (scs *Service) sendUserSyncData(sd *syncData) error { err := scs.sendSyncMsgToRemote(msg, sd.rc, func(syncResp SyncResponse, errResp error) { for _, userID := range syncResp.UsersSyncd { if err := scs.server.GetStore().SharedChannel().UpdateUserLastSyncAt(userID, sd.task.channelID, sd.rc.RemoteId); err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Cannot update shared channel user LastSyncAt", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Cannot update shared channel user LastSyncAt", mlog.String("user_id", userID), mlog.String("channel_id", sd.task.channelID), mlog.String("remote_id", sd.rc.RemoteId), @@ -425,7 +425,7 @@ func (scs *Service) sendUserSyncData(sd *syncData) error { } } if len(syncResp.UserErrors) != 0 { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Response indicates error for user(s) sync", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Response indicates error for user(s) sync", mlog.String("channel_id", sd.task.channelID), mlog.String("remote_id", sd.rc.RemoteId), mlog.Any("users", syncResp.UserErrors), @@ -439,7 +439,7 @@ func (scs *Service) sendUserSyncData(sd *syncData) error { func (scs *Service) sendAttachmentSyncData(sd *syncData) { for _, a := range sd.attachments { if err := scs.sendAttachmentForRemote(a.fi, a.post, sd.rc); err != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Cannot sync post attachment", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Cannot sync post attachment", mlog.String("post_id", a.post.Id), mlog.String("channel_id", sd.task.channelID), mlog.String("remote_id", sd.rc.RemoteId), @@ -457,7 +457,7 @@ func (scs *Service) sendPostSyncData(sd *syncData) error { return scs.sendSyncMsgToRemote(msg, sd.rc, func(syncResp SyncResponse, errResp error) { if len(syncResp.PostErrors) != 0 { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Response indicates error for post(s) sync", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Response indicates error for post(s) sync", mlog.String("channel_id", sd.task.channelID), mlog.String("remote_id", sd.rc.RemoteId), mlog.Any("posts", syncResp.PostErrors), @@ -478,7 +478,7 @@ func (scs *Service) sendReactionSyncData(sd *syncData) error { return scs.sendSyncMsgToRemote(msg, sd.rc, func(syncResp SyncResponse, errResp error) { if len(syncResp.ReactionErrors) != 0 { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Response indicates error for reactions(s) sync", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Response indicates error for reactions(s) sync", mlog.String("channel_id", sd.task.channelID), mlog.String("remote_id", sd.rc.RemoteId), mlog.Any("reaction_posts", syncResp.ReactionErrors), @@ -518,7 +518,7 @@ func (scs *Service) sendSyncMsgToRemote(msg *syncMsg, rc *model.RemoteCluster, f var syncResp SyncResponse if err2 := json.Unmarshal(rcResp.Payload, &syncResp); err2 != nil { - scs.server.GetLogger().Log(mlog.LvlSharedChannelServiceError, "Invalid sync msg response from remote cluster", + scs.server.Log().Log(mlog.LvlSharedChannelServiceError, "Invalid sync msg response from remote cluster", mlog.String("remote", rc.Name), mlog.String("channel_id", msg.ChannelId), mlog.Err(err2),