Reduce frequency of UpdateChannelsTeam() calls

[hloeung]

Hi,

On working on the channels pagination, I noticed there are quite a few calls to UpdateChannelsTeam(), some sequentially after another. With pagination in place, this increases the requests and load to the MM server.

For with this patch:

--- a/vendor/github.com/matterbridge/matterclient/channels.go
+++ b/vendor/github.com/matterbridge/matterclient/channels.go
@@ -229,6 +229,7 @@ func (m *Client) UpdateChannelsTeam(teamID string) error {

        var moreChannels []*model.Channel

+       m.logger.Errorf("HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go")
        for {
                mmchannels, resp, err = m.Client.GetPublicChannelsForTeam(teamID, idx, max, "")
                if err == nil {

With the patch above and Debug, I'm seeing logging like this:

[2022-11-06T08:30:22+11:00] DEBUG matterclient: WsReceiver response: &model.WebSocketResponse{Status:"OK", SeqReply:5, Data:map[string]interface {}{"node_id":"", "server_time":1.667683822499e+12, "text":"pong", "version":"6.6.0"}, Error:(*model.AppError)(nil)}
[2022-11-06T08:30:22+11:00] DEBUG matterclient: getting response: &model.WebSocketResponse{Status:"OK", SeqReply:5, Data:map[string]interface {}{"node_id":"", "server_time":1.667683822499e+12, "text":"pong", "version":"6.6.0"}, Error:(*model.AppError)(nil)}
[2022-11-06T08:30:22+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:30:26+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
DEBU[2022-11-06T08:30:28+11:00] Updating channels for &model.WebsocketBroadcast{OmitUsers:map[string]bool(nil), UserId:"m45ssk4t4bfwufbghxnmj89d4a", ChannelId:"", TeamId:"", ContainsSanitizedData:false, ContainsSensitiveData:false, ReliableClusterSend:false}
DEBU[2022-11-06T08:30:28+11:00] in handleWsMessage0
[2022-11-06T08:30:29+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:30:31+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go

[2022-11-06T08:33:23+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:33:26+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
DEBU[2022-11-06T08:33:29+11:00] Updating channels for &model.WebsocketBroadcast{OmitUsers:map[string]bool(nil), UserId:"m45ssk4t4bfwufbghxnmj89d4a", ChannelId:"", TeamId:"", ContainsSanitizedData:false, ContainsSensitiveData:false, ReliableClusterSend:false}
DEBU[2022-11-06T08:33:29+11:00] in handleWsMessage0
[2022-11-06T08:33:29+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:33:32+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go

[2022-11-06T08:33:23+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:33:26+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
DEBU[2022-11-06T08:33:29+11:00] Updating channels for &model.WebsocketBroadcast{OmitUsers:map[string]bool(nil), UserId:"m45ssk4t4bfwufbghxnmj89d4a", ChannelId:"", TeamId:"", ContainsSanitizedData:false, ContainsSensitiveData:false, ReliableClusterSend:false}
DEBU[2022-11-06T08:33:29+11:00] in handleWsMessage0
[2022-11-06T08:33:29+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:33:32+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
...
DEBU[2022-11-06T08:35:13+11:00] MMUser WsReceiver: &model.WebSocketEvent{event:"channel_viewed", data:map[string]interface {}{"channel_id":"pkn6xmxn37rix85w4uurjpkoqo"}, broadcast:(*model.WebsocketBroadcast)(0xc0004fee00), sequence:16, precomputedJSON:(*model.precomputedWebSocketEventJSON)(nil)}
[2022-11-06T08:35:13+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:35:13+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:35:16+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:35:17+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
DEBU[2022-11-06T08:35:19+11:00] in handleWsMessage4

It looks like maybe there's a channel/go routine to run this frequently? Does it need to be there now given that we call UpdateChannelsTeam() when it's not found in places?

Also, notice the calls seconds apart? These are then multiplied due to pagination.

[hloeung]

Adding this too, channel_viewed:

[2022-11-06T08:47:30+11:00] DEBUG matterclient: WsReceiver event: &model.WebSocketEvent{event:"channel_viewed", data:map[string]interface {}{"channel_id":"1tq37i8sqfrg7x611gifz8xf9y"}, broadcast:(*model.WebsocketBroadcast)(0xc0004fe4c0), sequence:35, precomputedJSON:(*model.precomputedWebSocketEventJSON)(nil)}
DEBU[2022-11-06T08:47:30+11:00] MMUser WsReceiver: &model.WebSocketEvent{event:"channel_viewed", data:map[string]interface {}{"channel_id":"1tq37i8sqfrg7x611gifz8xf9y"}, broadcast:(*model.WebsocketBroadcast)(0xc0004fe4c0), sequence:35, precomputedJSON:(*model.precomputedWebSocketEventJSON)(nil)}
TRAC[2022-11-06T08:47:30+11:00] handleWsMessage (*matterclient.Message)(0xc000118690)({
...
})
[2022-11-06T08:47:31+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:47:34+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
DEBU[2022-11-06T08:47:36+11:00] Updating channels for &model.WebsocketBroadcast{OmitUsers:map[string]bool(nil), UserId:"m45ssk4t4bfwufbghxnmj89d4a", ChannelId:"", TeamId:"", ContainsSanitizedData:false, ContainsSensitiveData:false, ReliableClusterSend:false}
DEBU[2022-11-06T08:47:36+11:00] in handleWsMessage0
[2022-11-06T08:47:37+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T08:47:37+11:00] DEBUG matterclient: WsReceiver response: &model.WebSocketResponse{Status:"OK", SeqReply:28, Data:map[string]interface {}{"node_id":"", "server_time":1.667684857597e+12, "text":"pong", "version":"6.6.0"}, Error:(*model.AppError)(nil)}
[2022-11-06T08:47:37+11:00] DEBUG matterclient: getting response: &model.WebSocketResponse{Status:"OK", SeqReply:28, Data:map[string]interface {}{"node_id":"", "server_time":1.667684857597e+12, "text":"pong", "version":"6.6.0"}, Error:(*model.AppError)(nil)}
[2022-11-06T08:47:40+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go

[hloeung]

Maybe it's a bug in this bit in checkWsActionMessage() in bridge/mattermost6/mattermost.go?

        if m.GetChannelName(rmsg.GetBroadcast().ChannelId) != "" {
                return
        }

[hloeung]

Oh, that's the channel I use for antiIdle. So somehow channelID is empty in the broadcast msg:

TRAC[2022-11-06T08:58:22+11:00] handleWsMessage (*matterclient.Message)(0xc0001129a0)({
 Raw: (*model.WebSocketEvent)(0xc000bc9b30)({
  event: (string) (len=14) "channel_viewed",
  data: (map[string]interface {}) (len=1) {
   (string) (len=10) "channel_id": (string) (len=26) "1tq37i8sqfrg7x611gifz8xf9y"
  },
  broadcast: (*model.WebsocketBroadcast)(0xc0017d2b00)({
   OmitUsers: (map[string]bool) <nil>,
   UserId: (string) (len=26) "m45ssk4t4bfwufbghxnmj89d4a",
   ChannelId: (string) "",
   TeamId: (string) "",
   ContainsSanitizedData: (bool) false,
   ContainsSensitiveData: (bool) false,
   ReliableClusterSend: (bool) false
  }),
  sequence: (int64) 45,
  precomputedJSON: (*model.precomputedWebSocketEventJSON)(<nil>)
 }),
 Post: (*model.Post)(<nil>),
 Team: (string) (len=9) "canonical",
 Channel: (string) "",
 Username: (string) "",
 Text: (string) "",
 Type: (string) "",
 UserID: (string) ""
})
TRAC[2022-11-06T08:58:22+11:00] eventchan (*bridge.Event)(0xc000cc2cc0)({
 Type: (string) (len=13) "status_change",
 Data: (*bridge.StatusChangeEvent)(0xc000cc2ca0)({
  UserID: (string) (len=26) "m45ssk4t4bfwufbghxnmj89d4a",
  Status: (string) (len=7) "offline"
 })
})  module=matterircd

[hloeung]

https://github.com/42wim/matterircd/pull/493 reduces the calls. There is still the issue where it's called multiple times in sequence ~4 secs apart:

[2022-11-06T09:40:35+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T09:40:38+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go
[2022-11-06T09:40:41+11:00] ERROR matterclient: HAW UpdateChannelsTeam() vendor/github.com/matterbridge/matterclient/channels.go

[hloeung]

Related PR https://github.com/matterbridge/matterclient/pull/2 reduces the subsequent calls to UpdateChannelsTeam()

[hloeung]

Finally got the last of it, UpdateChannels() is only called once on init then only when channel or user changes (that's additions and deletions/archiving).

[42wim]

Thanks for the debug job :)