From 686c2fbab7607d42183ae685a27ea3d7dce8c3f6 Mon Sep 17 00:00:00 2001 From: Christopher Speller Date: Fri, 27 Apr 2018 12:49:45 -0700 Subject: Structured logging (#8673) * Implementing structured logging * Changes to en.json to allow refactor to run. * Fixing global logger * Structured logger initalization. * Add caller. * Do some log redirection. * Auto refactor * Cleaning up l4g reference and removing dependancy. * Removing junk. * Copyright headers. * Fixing tests * Revert "Changes to en.json to allow refactor to run." This reverts commit fd8249e99bcad0231e6ea65cd77c32aae9a54026. * Fixing some auto refactor strangeness and typo. * Making keys more human readable. --- app/web_conn.go | 29 ++++++++++++++--------------- 1 file changed, 14 insertions(+), 15 deletions(-) (limited to 'app/web_conn.go') diff --git a/app/web_conn.go b/app/web_conn.go index 9ae5505b2..9d8134f34 100644 --- a/app/web_conn.go +++ b/app/web_conn.go @@ -8,10 +8,9 @@ import ( "sync/atomic" "time" + "github.com/mattermost/mattermost-server/mlog" "github.com/mattermost/mattermost-server/model" - "github.com/mattermost/mattermost-server/utils" - l4g "github.com/alecthomas/log4go" "github.com/gorilla/websocket" goi18n "github.com/nicksnyder/go-i18n/i18n" ) @@ -138,9 +137,9 @@ func (c *WebConn) readPump() { if err := c.WebSocket.ReadJSON(&req); err != nil { // browsers will appear as CloseNoStatusReceived if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { - l4g.Debug(fmt.Sprintf("websocket.read: client side closed socket userId=%v", c.UserId)) + mlog.Debug(fmt.Sprintf("websocket.read: client side closed socket userId=%v", c.UserId)) } else { - l4g.Debug(fmt.Sprintf("websocket.read: closing websocket for userId=%v error=%v", c.UserId, err.Error())) + mlog.Debug(fmt.Sprintf("websocket.read: closing websocket for userId=%v error=%v", c.UserId, err.Error())) } return @@ -177,7 +176,7 @@ func (c *WebConn) writePump() { if msg.EventType() == model.WEBSOCKET_EVENT_TYPING || msg.EventType() == model.WEBSOCKET_EVENT_STATUS_CHANGE || msg.EventType() == model.WEBSOCKET_EVENT_CHANNEL_VIEWED { - l4g.Info(fmt.Sprintf("websocket.slow: dropping message userId=%v type=%v channelId=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId)) + mlog.Info(fmt.Sprintf("websocket.slow: dropping message userId=%v type=%v channelId=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId)) skipSend = true } } @@ -196,9 +195,9 @@ func (c *WebConn) writePump() { if len(c.Send) >= SEND_DEADLOCK_WARN { if evtOk { - l4g.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v channelId=%v size=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId, len(msg.ToJson()))) + mlog.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v channelId=%v size=%v", c.UserId, msg.EventType(), evt.Broadcast.ChannelId, len(msg.ToJson()))) } else { - l4g.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v size=%v", c.UserId, msg.EventType(), len(msg.ToJson()))) + mlog.Error(fmt.Sprintf("websocket.full: message userId=%v type=%v size=%v", c.UserId, msg.EventType(), len(msg.ToJson()))) } } @@ -206,9 +205,9 @@ func (c *WebConn) writePump() { if err := c.WebSocket.WriteMessage(websocket.TextMessage, msgBytes); err != nil { // browsers will appear as CloseNoStatusReceived if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { - l4g.Debug(fmt.Sprintf("websocket.send: client side closed socket userId=%v", c.UserId)) + mlog.Debug(fmt.Sprintf("websocket.send: client side closed socket userId=%v", c.UserId)) } else { - l4g.Debug(fmt.Sprintf("websocket.send: closing websocket for userId=%v, error=%v", c.UserId, err.Error())) + mlog.Debug(fmt.Sprintf("websocket.send: closing websocket for userId=%v, error=%v", c.UserId, err.Error())) } return @@ -226,9 +225,9 @@ func (c *WebConn) writePump() { if err := c.WebSocket.WriteMessage(websocket.PingMessage, []byte{}); err != nil { // browsers will appear as CloseNoStatusReceived if websocket.IsCloseError(err, websocket.CloseNormalClosure, websocket.CloseNoStatusReceived) { - l4g.Debug(fmt.Sprintf("websocket.ticker: client side closed socket userId=%v", c.UserId)) + mlog.Debug(fmt.Sprintf("websocket.ticker: client side closed socket userId=%v", c.UserId)) } else { - l4g.Debug(fmt.Sprintf("websocket.ticker: closing websocket for userId=%v error=%v", c.UserId, err.Error())) + mlog.Debug(fmt.Sprintf("websocket.ticker: closing websocket for userId=%v error=%v", c.UserId, err.Error())) } return @@ -237,7 +236,7 @@ func (c *WebConn) writePump() { return case <-authTicker.C: if c.GetSessionToken() == "" { - l4g.Debug(fmt.Sprintf("websocket.authTicker: did not authenticate ip=%v", c.WebSocket.RemoteAddr())) + mlog.Debug(fmt.Sprintf("websocket.authTicker: did not authenticate ip=%v", c.WebSocket.RemoteAddr())) return } authTicker.Stop() @@ -261,7 +260,7 @@ func (webCon *WebConn) IsAuthenticated() bool { session, err := webCon.App.GetSession(webCon.GetSessionToken()) if err != nil { - l4g.Error(utils.T("api.websocket.invalid_session.error"), err.Error()) + mlog.Error(fmt.Sprintf("Invalid session err=%v", err.Error())) webCon.SetSessionToken("") webCon.SetSession(nil) webCon.SetSessionExpiresAt(0) @@ -334,7 +333,7 @@ func (webCon *WebConn) ShouldSendEvent(msg *model.WebSocketEvent) bool { if webCon.AllChannelMembers == nil { if result := <-webCon.App.Srv.Store.Channel().GetAllChannelMembersForUser(webCon.UserId, true); result.Err != nil { - l4g.Error("webhub.shouldSendEvent: " + result.Err.Error()) + mlog.Error("webhub.shouldSendEvent: " + result.Err.Error()) return false } else { webCon.AllChannelMembers = result.Data.(map[string]string) @@ -365,7 +364,7 @@ func (webCon *WebConn) IsMemberOfTeam(teamId string) bool { if currentSession == nil || len(currentSession.Token) == 0 { session, err := webCon.App.GetSession(webCon.GetSessionToken()) if err != nil { - l4g.Error(utils.T("api.websocket.invalid_session.error"), err.Error()) + mlog.Error(fmt.Sprintf("Invalid session err=%v", err.Error())) return false } else { webCon.SetSession(session) -- cgit v1.2.3-1-g7c22