MM-18266 Converting to structured logging the file app/web_con… (#12141)

Этот коммит содержится в:
Nikhil Ranjan
2019-09-11 17:16:33 +02:00
коммит произвёл Ben Schumacher
родитель df85bd422f
Коммит a5f04802e8

Просмотреть файл

@@ -144,9 +144,9 @@ func (c *WebConn) readPump() {
if err := c.WebSocket.ReadJSON(&req); err != nil { if err := c.WebSocket.ReadJSON(&req); err != nil {
// browsers will appear as CloseNoStatusReceived // browsers will appear as CloseNoStatusReceived
if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) {
mlog.Debug(fmt.Sprintf("websocket.read: client side closed socket userId=%v", c.UserId)) mlog.Debug("websocket.read: client side closed socket", mlog.String("user_id", c.UserId))
} else { } else {
mlog.Debug(fmt.Sprintf("websocket.read: closing websocket for userId=%v error=%v", c.UserId, err.Error())) mlog.Debug("websocket.read: closing websocket", mlog.String("user_id", c.UserId), mlog.Err(err))
} }
return return
} }
@@ -181,7 +181,12 @@ func (c *WebConn) writePump() {
if msg.EventType() == model.WEBSOCKET_EVENT_TYPING || if msg.EventType() == model.WEBSOCKET_EVENT_TYPING ||
msg.EventType() == model.WEBSOCKET_EVENT_STATUS_CHANGE || msg.EventType() == model.WEBSOCKET_EVENT_STATUS_CHANGE ||
msg.EventType() == model.WEBSOCKET_EVENT_CHANNEL_VIEWED { msg.EventType() == model.WEBSOCKET_EVENT_CHANNEL_VIEWED {
mlog.Info(fmt.Sprintf("websocket.slow: dropping message userId=%v type=%v channelId=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId)) mlog.Info(
"websocket.slow: dropping message",
mlog.String("user_id", c.UserId),
mlog.String("type", msg.EventType()),
mlog.String("channel_id", evt.Broadcast.ChannelId),
)
skipSend = true skipSend = true
} }
} }
@@ -200,9 +205,20 @@ func (c *WebConn) writePump() {
if len(c.Send) >= SEND_DEADLOCK_WARN { if len(c.Send) >= SEND_DEADLOCK_WARN {
if evtOk { if evtOk {
mlog.Warn(fmt.Sprintf("websocket.full: message userId=%v type=%v channelId=%v size=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId, len(msg.ToJson()))) mlog.Warn(
"websocket.full",
mlog.String("user_id", c.UserId),
mlog.String("type", msg.EventType()),
mlog.String("channel_id", evt.Broadcast.ChannelId),
mlog.Int("size", len(msg.ToJson())),
)
} else { } else {
mlog.Warn(fmt.Sprintf("websocket.full: message userId=%v type=%v size=%v", c.UserId, msg.EventType(), len(msg.ToJson()))) mlog.Warn(
"websocket.full",
mlog.String("user_id", c.UserId),
mlog.String("type", msg.EventType()),
mlog.Int("size", len(msg.ToJson())),
)
} }
} }
@@ -210,9 +226,9 @@ func (c *WebConn) writePump() {
if err := c.WebSocket.WriteMessage(websocket.TextMessage, msgBytes); err != nil { if err := c.WebSocket.WriteMessage(websocket.TextMessage, msgBytes); err != nil {
// browsers will appear as CloseNoStatusReceived // browsers will appear as CloseNoStatusReceived
if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) {
mlog.Debug(fmt.Sprintf("websocket.send: client side closed socket userId=%v", c.UserId)) mlog.Debug("websocket.send: client side closed socket", mlog.String("user_id", c.UserId))
} else { } else {
mlog.Debug(fmt.Sprintf("websocket.send: closing websocket for userId=%v, error=%v", c.UserId, err.Error())) mlog.Debug("websocket.send: closing websocket", mlog.String("user_id", c.UserId), mlog.Err(err))
} }
return return
} }
@@ -229,9 +245,9 @@ func (c *WebConn) writePump() {
if err := c.WebSocket.WriteMessage(websocket.PingMessage, []byte{}); err != nil { if err := c.WebSocket.WriteMessage(websocket.PingMessage, []byte{}); err != nil {
// browsers will appear as CloseNoStatusReceived // browsers will appear as CloseNoStatusReceived
if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) {
mlog.Debug(fmt.Sprintf("websocket.ticker: client side closed socket userId=%v", c.UserId)) mlog.Debug("websocket.ticker: client side closed socket", mlog.String("user_id", c.UserId))
} else { } else {
mlog.Debug(fmt.Sprintf("websocket.ticker: closing websocket for userId=%v error=%v", c.UserId, err.Error())) mlog.Debug("websocket.ticker: closing websocket", mlog.String("user_id", c.UserId), mlog.Err(err))
} }
return return
} }
@@ -241,7 +257,7 @@ func (c *WebConn) writePump() {
case <-authTicker.C: case <-authTicker.C:
if c.GetSessionToken() == "" { if c.GetSessionToken() == "" {
mlog.Debug(fmt.Sprintf("websocket.authTicker: did not authenticate ip=%v", c.WebSocket.RemoteAddr())) mlog.Debug("websocket.authTicker: did not authenticate", mlog.Any("ip_address", c.WebSocket.RemoteAddr()))
return return
} }
authTicker.Stop() authTicker.Stop()
@@ -265,7 +281,7 @@ func (webCon *WebConn) IsAuthenticated() bool {
session, err := webCon.App.GetSession(webCon.GetSessionToken()) session, err := webCon.App.GetSession(webCon.GetSessionToken())
if err != nil { if err != nil {
mlog.Error(fmt.Sprintf("Invalid session err=%v", err.Error())) mlog.Error("Invalid session.", mlog.Err(err))
webCon.SetSessionToken("") webCon.SetSessionToken("")
webCon.SetSession(nil) webCon.SetSession(nil)
webCon.SetSessionExpiresAt(0) webCon.SetSessionExpiresAt(0)
@@ -338,7 +354,7 @@ func (webCon *WebConn) ShouldSendEvent(msg *model.WebSocketEvent) bool {
if webCon.AllChannelMembers == nil { if webCon.AllChannelMembers == nil {
result, err := webCon.App.Srv.Store.Channel().GetAllChannelMembersForUser(webCon.UserId, true, false) result, err := webCon.App.Srv.Store.Channel().GetAllChannelMembersForUser(webCon.UserId, true, false)
if err != nil { if err != nil {
mlog.Error("webhub.shouldSendEvent: " + err.Error()) mlog.Error("webhub.shouldSendEvent.", mlog.Err(err))
return false return false
} }
webCon.AllChannelMembers = result webCon.AllChannelMembers = result
@@ -359,7 +375,7 @@ func (webCon *WebConn) ShouldSendEvent(msg *model.WebSocketEvent) bool {
if msg.Event == model.WEBSOCKET_EVENT_USER_UPDATED && webCon.GetSession().Props[model.SESSION_PROP_IS_GUEST] == "true" { if msg.Event == model.WEBSOCKET_EVENT_USER_UPDATED && webCon.GetSession().Props[model.SESSION_PROP_IS_GUEST] == "true" {
canSee, err := webCon.App.UserCanSeeOtherUser(webCon.UserId, msg.Data["user"].(*model.User).Id) canSee, err := webCon.App.UserCanSeeOtherUser(webCon.UserId, msg.Data["user"].(*model.User).Id)
if err != nil { if err != nil {
mlog.Error("webhub.shouldSendEvent: " + err.Error()) mlog.Error("webhub.shouldSendEvent.", mlog.Err(err))
return false return false
} }
return canSee return canSee
@@ -374,7 +390,7 @@ func (webCon *WebConn) IsMemberOfTeam(teamId string) bool {
if currentSession == nil || len(currentSession.Token) == 0 { if currentSession == nil || len(currentSession.Token) == 0 {
session, err := webCon.App.GetSession(webCon.GetSessionToken()) session, err := webCon.App.GetSession(webCon.GetSessionToken())
if err != nil { if err != nil {
mlog.Error(fmt.Sprintf("Invalid session err=%v", err.Error())) mlog.Error("Invalid session.", mlog.Err(err))
return false return false
} }
webCon.SetSession(session) webCon.SetSession(session)