Skip to content

Commit

Permalink
[GH-244]: Fixed issue "Status sync job exits if an error happens for …
Browse files Browse the repository at this point in the history 
…a single user" by added additional logging (#245)

* [MI-2664]:Fixed issue #244 on ms calender to add additional logging (#2)

* [MI-2664]:Fixed issue #244 on ms calender to add additional logging

* [MI-2664]:Added comment for skipping user

* [MI-2664]:Fixed unit test cases

* [MI-2664]:Fix lint errors

* [MI-2664]:Added conditional logging

* [MI-2664]:Added constants for limit

* [MI-2664]:Fixed review comments

* [MI-2664]:Fixed review comments

* [MI-2687]:Fixed review comments given by mattermost team on issue#244 of mscalender plugin (#3)

* [MI-2687]:Fixed review comments given by mattermost team on issue #244 of mscalender plugin

* [MI-2687]:Fixed unit test cases

* [MI-2687]:Fixed review fixes

* [MI-2705]:Added summary for status sync job (#4)

* [MI-2705]:Added summary for status sync job

* [MI-2705]:Fixed review comments

* Fixed lint errors (#243)

* [MI-2705]:Fixed review comments

* [MI-2705]:Fixed review comments

---------

Co-authored-by: Manoj Malik <[email protected]>

* [MM-244]:Fixed lint errors

* [MM-244]:Added a check for summary to be nill

* [MM-244]:Added addtional check for user error

* [MM-244]:Fixed lint errors

* [MM-244]:Fixed review comments

---------

Co-authored-by: Manoj Malik <[email protected]>
  • Loading branch information
@Kshitij-Katiyar @manojmalik20
Kshitij-Katiyar and manojmalik20 authored Mar 22, 2023
1 parent c3f7cdd commit 347546a
Show file tree
Hide file tree
Showing 5 changed files with 110 additions and 56 deletions.
4 changes: 2 additions & 2 deletions server/command/availability.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,14 +6,14 @@ package command
func (c *Command) debugAvailability(parameters ...string) (string, bool, error) {
switch {
case len(parameters) == 0:
resString, err := c.MSCalendar.Sync(c.Args.UserId)
resString, _, err := c.MSCalendar.Sync(c.Args.UserId)
if err != nil {
return "", false, err
}

return resString, false, nil
case len(parameters) == 1 && parameters[0] == "all":
resString, err := c.MSCalendar.SyncAll()
resString, _, err := c.MSCalendar.SyncAll()
if err != nil {
return "", false, err
}
Expand Down
4 changes: 2 additions & 2 deletions server/jobs/status_sync_job.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,10 +23,10 @@ func NewStatusSyncJob() RegisteredJob {
func runSyncJob(env mscalendar.Env) {
env.Logger.Debugf("User status sync job beginning")

_, err := mscalendar.New(env, "").SyncAll()
_, syncJobSummary, err := mscalendar.New(env, "").SyncAll()
if err != nil {
env.Logger.Errorf("Error during user status sync job. err=%v", err)
}

env.Logger.Debugf("User status sync job finished")
env.Logger.Debugf("User status sync job finished.\nSummary\nNumber of users processed:- %d\nNumber of users had their status changed:- %d\nNumber of users had errors:- %d", syncJobSummary.NumberOfUsersProcessed, syncJobSummary.NumberOfUsersStatusChanged, syncJobSummary.NumberOfUsersFailedStatusChanged)
}
134 changes: 93 additions & 41 deletions server/mscalendar/availability.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import (
"time"

"github.com/mattermost/mattermost-server/v5/model"
"github.com/pkg/errors"

"github.com/mattermost/mattermost-plugin-mscalendar/server/config"
"github.com/mattermost/mattermost-plugin-mscalendar/server/mscalendar/views"
Expand All @@ -21,78 +22,102 @@ const (
StatusSyncJobInterval = 5 * time.Minute
upcomingEventNotificationTime = 10 * time.Minute
upcomingEventNotificationWindow = (StatusSyncJobInterval * 11) / 10 // 110% of the interval
logTruncateMsg = "We've truncated the logs due to too many messages"
logTruncateLimit = 5
)

type StatusSyncJobSummary struct {
NumberOfUsersFailedStatusChanged int
NumberOfUsersStatusChanged int
NumberOfUsersProcessed int
}

type Availability interface {
GetCalendarViews(users []*store.User) ([]*remote.ViewCalendarResponse, error)
Sync(mattermostUserID string) (string, error)
SyncAll() (string, error)
Sync(mattermostUserID string) (string, *StatusSyncJobSummary, error)
SyncAll() (string, *StatusSyncJobSummary, error)
}

func (m *mscalendar) Sync(mattermostUserID string) (string, error) {
func (m *mscalendar) Sync(mattermostUserID string) (string, *StatusSyncJobSummary, error) {
user, err := m.Store.LoadUserFromIndex(mattermostUserID)
if err != nil {
return "", err
return "", nil, err
}

return m.syncUsers(store.UserIndex{user})
}

func (m *mscalendar) SyncAll() (string, error) {
func (m *mscalendar) SyncAll() (string, *StatusSyncJobSummary, error) {
err := m.Filter(withSuperuserClient)
if err != nil {
return "", err
return "", &StatusSyncJobSummary{}, errors.Wrap(err, "not able to filter the super user client")
}

userIndex, err := m.Store.LoadUserIndex()
if err != nil {
if err.Error() == "not found" {
return "No users found in user index", nil
return "No users found in user index", &StatusSyncJobSummary{}, nil
}
return "", err
return "", &StatusSyncJobSummary{}, errors.Wrap(err, "not able to load the users from user index")
}

return m.syncUsers(userIndex)
}

func (m *mscalendar) syncUsers(userIndex store.UserIndex) (string, error) {
func (m *mscalendar) syncUsers(userIndex store.UserIndex) (string, *StatusSyncJobSummary, error) {
syncJobSummary := &StatusSyncJobSummary{}
if len(userIndex) == 0 {
return "No connected users found", nil
return "No connected users found", syncJobSummary, nil
}
syncJobSummary.NumberOfUsersProcessed = len(userIndex)

numberOfLogs := 0
users := []*store.User{}
for _, u := range userIndex {
// TODO fetch users from kvstore in batches, and process in batches instead of all at once
user, err := m.Store.LoadUser(u.MattermostUserID)
if err != nil {
return "", err
syncJobSummary.NumberOfUsersFailedStatusChanged++
if numberOfLogs < logTruncateLimit {
m.Logger.Warnf("Not able to load user %s from user index. err=%v", u.MattermostUserID, err)
} else if numberOfLogs == logTruncateLimit {
m.Logger.Warnf(logTruncateMsg)
}
numberOfLogs++

// In case of error in loading, skip this user and continue with the next user
continue
}
if user.Settings.UpdateStatus || user.Settings.ReceiveReminders {
users = append(users, user)
}
}
if len(users) == 0 {
return "No users need to be synced", nil
return "No users need to be synced", syncJobSummary, nil
}

calendarViews, err := m.GetCalendarViews(users)
if err != nil {
return "", err
return "", syncJobSummary, errors.Wrap(err, "not able to get calendar views for connected users")
}
if len(calendarViews) == 0 {
return "No calendar views found", nil
return "No calendar views found", syncJobSummary, nil
}

m.deliverReminders(users, calendarViews)
out, err := m.setUserStatuses(users, calendarViews)
out, numberOfUsersStatusChanged, numberOfUsersFailedStatusChanged, err := m.setUserStatuses(users, calendarViews)
if err != nil {
return "", err
return "", syncJobSummary, errors.Wrap(err, "error setting the user statuses")
}

return out, nil
syncJobSummary.NumberOfUsersFailedStatusChanged += numberOfUsersFailedStatusChanged
syncJobSummary.NumberOfUsersStatusChanged = numberOfUsersStatusChanged

return out, syncJobSummary, nil
}

func (m *mscalendar) deliverReminders(users []*store.User, calendarViews []*remote.ViewCalendarResponse) {
numberOfLogs := 0
toNotify := []*store.User{}
for _, u := range users {
if u.Settings.ReceiveReminders {
Expand All @@ -114,7 +139,12 @@ func (m *mscalendar) deliverReminders(users []*store.User, calendarViews []*remo
continue
}
if view.Error != nil {
m.Logger.Warnf("Error getting availability for %s. err=%s", user.Remote.Mail, view.Error.Message)
if numberOfLogs < logTruncateLimit {
m.Logger.Warnf("Error getting availability for %s. err=%s", user.MattermostUserID, view.Error.Message)
} else if numberOfLogs == logTruncateLimit {
m.Logger.Warnf(logTruncateMsg)
}
numberOfLogs++
continue
}

Expand All @@ -123,15 +153,16 @@ func (m *mscalendar) deliverReminders(users []*store.User, calendarViews []*remo
}
}

func (m *mscalendar) setUserStatuses(users []*store.User, calendarViews []*remote.ViewCalendarResponse) (string, error) {
func (m *mscalendar) setUserStatuses(users []*store.User, calendarViews []*remote.ViewCalendarResponse) (string, int, int, error) {
numberOfLogs, numberOfUserStatusChange, numberOfUserErrorInStatusChange := 0, 0, 0
toUpdate := []*store.User{}
for _, u := range users {
if u.Settings.UpdateStatus {
toUpdate = append(toUpdate, u)
}
}
if len(toUpdate) == 0 {
return "No users want their status updated", nil
return "No users want their status updated", numberOfUserStatusChange, numberOfUserErrorInStatusChange, nil
}

mattermostUserIDs := []string{}
Expand All @@ -143,7 +174,7 @@ func (m *mscalendar) setUserStatuses(users []*store.User, calendarViews []*remot

statuses, appErr := m.PluginAPI.GetMattermostUserStatusesByIds(mattermostUserIDs)
if appErr != nil {
return "", appErr
return "", numberOfUserStatusChange, numberOfUserErrorInStatusChange, errors.Wrap(appErr, "error in getting Mattermost user statuses for connected users")
}
statusMap := map[string]*model.Status{}
for _, s := range statuses {
Expand All @@ -152,12 +183,19 @@ func (m *mscalendar) setUserStatuses(users []*store.User, calendarViews []*remot

var res string
for _, view := range calendarViews {
isStatusChanged := false
user, ok := usersByRemoteID[view.RemoteUserID]
if !ok {
continue
}
if view.Error != nil {
m.Logger.Warnf("Error getting availability for %s. err=%s", user.Remote.Mail, view.Error.Message)
if numberOfLogs < logTruncateLimit {
m.Logger.Warnf("Error getting availability for %s. err=%s", user.MattermostUserID, view.Error.Message)
} else if numberOfLogs == logTruncateLimit {
m.Logger.Warnf(logTruncateMsg)
}
numberOfLogs++
numberOfUserErrorInStatusChange++
continue
}

Expand All @@ -168,22 +206,32 @@ func (m *mscalendar) setUserStatuses(users []*store.User, calendarViews []*remot
}

var err error
res, err = m.setStatusFromCalendarView(user, status, view)
res, isStatusChanged, err = m.setStatusFromCalendarView(user, status, view)
if err != nil {
m.Logger.Warnf("Error setting user %s status. err=%v", user.Remote.Mail, err)
if numberOfLogs < logTruncateLimit {
m.Logger.Warnf("Error setting user %s status. err=%v", user.MattermostUserID, err)
} else if numberOfLogs == logTruncateLimit {
m.Logger.Warnf(logTruncateMsg)
}
numberOfLogs++
numberOfUserErrorInStatusChange++
}
if isStatusChanged {
numberOfUserStatusChange++
}
}
if res != "" {
return res, nil
return res, numberOfUserStatusChange, numberOfUserErrorInStatusChange, nil
}

return utils.JSONBlock(calendarViews), nil
return utils.JSONBlock(calendarViews), numberOfUserStatusChange, numberOfUserErrorInStatusChange, nil
}

func (m *mscalendar) setStatusFromCalendarView(user *store.User, status *model.Status, res *remote.ViewCalendarResponse) (string, error) {
func (m *mscalendar) setStatusFromCalendarView(user *store.User, status *model.Status, res *remote.ViewCalendarResponse) (string, bool, error) {
isStatusChanged := false
currentStatus := status.Status
if currentStatus == model.STATUS_OFFLINE && !user.Settings.GetConfirmation {
return "User offline and does not want status change confirmations. No status change", nil
return "User offline and does not want status change confirmations. No status change", isStatusChanged, nil
}

events := filterBusyEvents(res.Events)
Expand All @@ -193,7 +241,7 @@ func (m *mscalendar) setStatusFromCalendarView(user *store.User, status *model.S
}

if len(user.ActiveEvents) == 0 && len(events) == 0 {
return "No events in local or remote. No status change.", nil
return "No events in local or remote. No status change.", isStatusChanged, nil
}

if len(user.ActiveEvents) > 0 && len(events) == 0 {
Expand All @@ -205,15 +253,16 @@ func (m *mscalendar) setStatusFromCalendarView(user *store.User, status *model.S
}
err := m.setStatusOrAskUser(user, status, events, true)
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in setting user status for user %s", user.MattermostUserID)
}
isStatusChanged = true
}

err := m.Store.StoreUserActiveEvents(user.MattermostUserID, []string{})
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in storing active events for user %s", user.MattermostUserID)
}
return message, nil
return message, isStatusChanged, nil
}

remoteHashes := []string{}
Expand All @@ -235,19 +284,20 @@ func (m *mscalendar) setStatusFromCalendarView(user *store.User, status *model.S
m.Store.StoreUser(user)
err = m.Store.StoreUserActiveEvents(user.MattermostUserID, remoteHashes)
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in storing active events for user %s", user.MattermostUserID)
}
return "User was already marked as busy. No status change.", nil
return "User was already marked as busy. No status change.", isStatusChanged, nil
}
err = m.setStatusOrAskUser(user, status, events, false)
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in setting user status for user %s", user.MattermostUserID)
}
isStatusChanged = true
err = m.Store.StoreUserActiveEvents(user.MattermostUserID, remoteHashes)
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in storing active events for user %s", user.MattermostUserID)
}
return fmt.Sprintf("User was free, but is now busy (%s). Set status to busy.", busyStatus), nil
return fmt.Sprintf("User was free, but is now busy (%s). Set status to busy.", busyStatus), isStatusChanged, nil
}

newEventExists := false
Expand All @@ -266,23 +316,25 @@ func (m *mscalendar) setStatusFromCalendarView(user *store.User, status *model.S
}

if !newEventExists {
return fmt.Sprintf("No change in active events. Total number of events: %d", len(events)), nil
return fmt.Sprintf("No change in active events. Total number of events: %d", len(events)), isStatusChanged, nil
}

message := "User is already busy. No status change."
if currentStatus != busyStatus {
err := m.setStatusOrAskUser(user, status, events, false)
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in setting user status for user %s", user.MattermostUserID)
}
isStatusChanged = true
message = fmt.Sprintf("User was free, but is now busy. Set status to busy (%s).", busyStatus)
}

err := m.Store.StoreUserActiveEvents(user.MattermostUserID, remoteHashes)
if err != nil {
return "", err
return "", isStatusChanged, errors.Wrapf(err, "error in storing active events for user %s", user.MattermostUserID)
}
return message, nil

return message, isStatusChanged, nil
}

// setStatusOrAskUser to which status change, and whether it should update the status automatically or ask the user.
Expand Down
10 changes: 5 additions & 5 deletions server/mscalendar/availability_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -155,13 +155,13 @@ func TestSyncStatusAll(t *testing.T) {
}

if tc.shouldLogError {
logger.EXPECT().Warnf("Error getting availability for %s. err=%s", "[email protected]", tc.apiError.Message).Times(1)
logger.EXPECT().Warnf("Error getting availability for %s. err=%s", "user_mm_id", tc.apiError.Message).Times(1)
} else {
logger.EXPECT().Warnf(gomock.Any()).Times(0)
}

m := New(env, "")
res, err := m.SyncAll()
res, _, err := m.SyncAll()
require.Nil(t, err)
require.NotEmpty(t, res)
})
Expand Down Expand Up @@ -223,7 +223,7 @@ func TestSyncStatusUserConfig(t *testing.T) {
tc.runAssertions(env.Dependencies, client)

mscalendar := New(env, "")
_, err := mscalendar.SyncAll()
_, _, err := mscalendar.SyncAll()
require.Nil(t, err)
})
}
Expand Down Expand Up @@ -315,13 +315,13 @@ func TestReminders(t *testing.T) {
}

if tc.shouldLogError {
logger.EXPECT().Warnf("Error getting availability for %s. err=%s", "[email protected]", tc.apiError.Message).Times(1)
logger.EXPECT().Warnf("Error getting availability for %s. err=%s", "user_mm_id", tc.apiError.Message).Times(1)
} else {
logger.EXPECT().Warnf(gomock.Any()).Times(0)
}

m := New(env, "")
res, err := m.SyncAll()
res, _, err := m.SyncAll()
require.Nil(t, err)
require.NotEmpty(t, res)
})
Expand Down
Loading

0 comments on commit 347546a

Please sign in to comment.