diff --git a/server/channels/app/platform/web_conn.go b/server/channels/app/platform/web_conn.go index 02b8cd8687..ac72c98cdf 100644 --- a/server/channels/app/platform/web_conn.go +++ b/server/channels/app/platform/web_conn.go @@ -27,15 +27,16 @@ import ( ) const ( - sendQueueSize = 256 - sendSlowWarn = (sendQueueSize * 50) / 100 - sendFullWarn = (sendQueueSize * 95) / 100 - writeWaitTime = 30 * time.Second - pongWaitTime = 100 * time.Second - pingInterval = (pongWaitTime * 6) / 10 - authCheckInterval = 5 * time.Second - webConnMemberCacheTime = 1000 * 60 * 30 // 30 minutes - deadQueueSize = 128 // Approximated from /proc/sys/net/core/wmem_default / 2048 (avg msg size) + sendQueueSize = 256 + sendSlowWarn = (sendQueueSize * 50) / 100 + sendFullWarn = (sendQueueSize * 95) / 100 + writeWaitTime = 30 * time.Second + pongWaitTime = 100 * time.Second + pingInterval = (pongWaitTime * 6) / 10 + authCheckInterval = 5 * time.Second + webConnMemberCacheTime = 1000 * 60 * 30 // 30 minutes + deadQueueSize = 128 // Approximated from /proc/sys/net/core/wmem_default / 2048 (avg msg size) + websocketSuppressWarnThreshold = time.Minute ) const ( @@ -112,6 +113,13 @@ type WebConn struct { endWritePump chan struct{} pumpFinished chan struct{} pluginPosted chan pluginWSPostedHook + + // These counters are to suppress spammy websocket.slow + // and websocket.full logs which happen continuously, if they + // do happen. To improve the situation, we log them only once + // per minute. + lastLogTimeSlow time.Time + lastLogTimeFull time.Time } // CheckConnResult indicates whether a connectionID was present in the hub or not. @@ -215,6 +223,8 @@ func (ps *PlatformService) NewWebConn(cfg *WebConnConfig, suite SuiteIFace, runn endWritePump: make(chan struct{}), pumpFinished: make(chan struct{}), pluginPosted: make(chan pluginWSPostedHook, 10), + lastLogTimeSlow: time.Now(), + lastLogTimeFull: time.Now(), } wc.SetSession(&cfg.Session) @@ -460,7 +470,7 @@ func (wc *WebConn) writePump() { continue } - if len(wc.send) >= sendFullWarn { + if len(wc.send) >= sendFullWarn && time.Since(wc.lastLogTimeFull) > websocketSuppressWarnThreshold { logData := []mlog.Field{ mlog.String("user_id", wc.UserId), mlog.String("type", msg.EventType()), @@ -471,6 +481,7 @@ func (wc *WebConn) writePump() { } mlog.Warn("websocket.full", logData...) + wc.lastLogTimeFull = time.Now() } if evtOk { @@ -711,11 +722,15 @@ func (wc *WebConn) ShouldSendEvent(msg *model.WebSocketEvent) bool { case model.WebsocketEventTyping, model.WebsocketEventStatusChange, model.WebsocketEventChannelViewed: - mlog.Warn( - "websocket.slow: dropping message", - mlog.String("user_id", wc.UserId), - mlog.String("type", msg.EventType()), - ) + if time.Since(wc.lastLogTimeSlow) > websocketSuppressWarnThreshold { + mlog.Warn( + "websocket.slow: dropping message", + mlog.String("user_id", wc.UserId), + mlog.String("type", msg.EventType()), + ) + // Reset timer to now. + wc.lastLogTimeSlow = time.Now() + } return false } }