1
0
mirror of https://github.com/mattermost/focalboard.git synced 2025-11-06 09:19:31 +02:00

Logger for FocalBoard server (#466)

- structured, asynchronous logging
- supports discreet log levels, including custom levels
- supports output to console, files, and all common log aggregators.
- supports JSON, plain text and GELF formats
- lazy formatting and writing
This commit is contained in:
Doug Lauder
2021-05-29 02:23:10 -04:00
committed by GitHub
parent fe6b0d04b3
commit 417de9f837
29 changed files with 1150 additions and 275 deletions

View File

@@ -12,6 +12,7 @@ import (
"github.com/gorilla/websocket"
"github.com/mattermost/focalboard/server/auth"
"github.com/mattermost/focalboard/server/model"
"github.com/mattermost/focalboard/server/services/mlog"
"github.com/mattermost/focalboard/server/services/store"
)
@@ -32,6 +33,7 @@ type Server struct {
hub Hub
singleUserToken string
isMattermostAuth bool
logger *mlog.Logger
}
// UpdateMsg is sent on block updates
@@ -68,7 +70,7 @@ type websocketSession struct {
}
// NewServer creates a new Server.
func NewServer(auth *auth.Auth, singleUserToken string, isMattermostAuth bool) *Server {
func NewServer(auth *auth.Auth, singleUserToken string, isMattermostAuth bool, logger *mlog.Logger) *Server {
return &Server{
listeners: make(map[string][]*websocket.Conn),
upgrader: websocket.Upgrader{
@@ -79,6 +81,7 @@ func NewServer(auth *auth.Auth, singleUserToken string, isMattermostAuth bool) *
auth: auth,
singleUserToken: singleUserToken,
isMattermostAuth: isMattermostAuth,
logger: logger,
}
}
@@ -91,13 +94,13 @@ func (ws *Server) handleWebSocketOnChange(w http.ResponseWriter, r *http.Request
// Upgrade initial GET request to a websocket
client, err := ws.upgrader.Upgrade(w, r, nil)
if err != nil {
log.Printf("ERROR upgrading to websocket: %v", err)
ws.logger.Error("ERROR upgrading to websocket", mlog.Err(err))
return
}
// Make sure we close the connection when the function returns
defer func() {
log.Printf("DISCONNECT WebSocket onChange, client: %s", client.RemoteAddr())
ws.logger.Debug("DISCONNECT WebSocket onChange", mlog.Stringer("client", client.RemoteAddr()))
// Remove client from listeners
ws.removeListener(client)
@@ -119,7 +122,10 @@ func (ws *Server) handleWebSocketOnChange(w http.ResponseWriter, r *http.Request
for {
_, p, err := client.ReadMessage()
if err != nil {
log.Printf("ERROR WebSocket onChange, client: %s, err: %v", client.RemoteAddr(), err)
ws.logger.Error("ERROR WebSocket onChange",
mlog.Stringer("client", client.RemoteAddr()),
mlog.Err(err),
)
ws.removeListener(client)
break
@@ -130,7 +136,7 @@ func (ws *Server) handleWebSocketOnChange(w http.ResponseWriter, r *http.Request
err = json.Unmarshal(p, &command)
if err != nil {
// handle this error
log.Printf(`ERROR webSocket parsing command JSON: %v`, string(p))
ws.logger.Error(`ERROR webSocket parsing command`, mlog.String("json", string(p)))
continue
}
@@ -139,23 +145,32 @@ func (ws *Server) handleWebSocketOnChange(w http.ResponseWriter, r *http.Request
if ws.auth.DoesUserHaveWorkspaceAccess(userID, command.WorkspaceID) {
wsSession.workspaceID = command.WorkspaceID
} else {
log.Printf(`ERROR User doesn't have permissions to read the workspace: %s`, command.WorkspaceID)
ws.logger.Error(`ERROR User doesn't have permissions to read the workspace`, mlog.String("workspaceID", command.WorkspaceID))
continue
}
}
switch command.Action {
case "AUTH":
log.Printf(`Command: AUTH, client: %s`, client.RemoteAddr())
ws.logger.Debug(`Command: AUTH`, mlog.Stringer("client", client.RemoteAddr()))
ws.authenticateListener(&wsSession, command.WorkspaceID, command.Token)
case "ADD":
log.Printf(`Command: Add workspaceID: %s, blockIDs: %v, client: %s`, wsSession.workspaceID, command.BlockIDs, client.RemoteAddr())
ws.logger.Debug(`Command: ADD`,
mlog.String("workspaceID", wsSession.workspaceID),
mlog.Array("blockIDs", command.BlockIDs),
mlog.Stringer("client", client.RemoteAddr()),
)
ws.addListener(&wsSession, &command)
case "REMOVE":
log.Printf(`Command: Remove workspaceID: %s, blockID: %v, client: %s`, wsSession.workspaceID, command.BlockIDs, client.RemoteAddr())
ws.logger.Debug(`Command: REMOVE`,
mlog.String("workspaceID", wsSession.workspaceID),
mlog.Array("blockIDs", command.BlockIDs),
mlog.Stringer("client", client.RemoteAddr()),
)
ws.removeListenerFromBlocks(&wsSession, &command)
default:
log.Printf(`ERROR webSocket command, invalid action: %v`, command.Action)
ws.logger.Error(`ERROR webSocket command, invalid action`, mlog.String("action", command.Action))
}
}
}
@@ -177,7 +192,7 @@ func (ws *Server) isValidSessionToken(token, workspaceID string) bool {
func (ws *Server) authenticateListener(wsSession *websocketSession, workspaceID, token string) {
if wsSession.isAuthenticated {
// Do not allow multiple auth calls (for security)
log.Printf("authenticateListener: Ignoring already authenticated session")
ws.logger.Debug("authenticateListener: Ignoring already authenticated session", mlog.String("workspaceID", workspaceID))
return
}
@@ -192,7 +207,7 @@ func (ws *Server) authenticateListener(wsSession *websocketSession, workspaceID,
wsSession.workspaceID = workspaceID
wsSession.isAuthenticated = true
log.Printf("authenticateListener: Authenticated, workspaceID: %s", workspaceID)
ws.logger.Debug("authenticateListener: Authenticated", mlog.String("workspaceID", workspaceID))
}
func (ws *Server) getAuthenticatedWorkspaceID(wsSession *websocketSession, command *WebsocketCommand) (string, error) {
@@ -203,7 +218,7 @@ func (ws *Server) getAuthenticatedWorkspaceID(wsSession *websocketSession, comma
// If not authenticated, try to authenticate the read token against the supplied workspaceID
workspaceID := command.WorkspaceID
if len(workspaceID) == 0 {
log.Printf("getAuthenticatedWorkspaceID: No workspace")
ws.logger.Error("getAuthenticatedWorkspaceID: No workspace")
return "", errors.New("No workspace")
}
@@ -234,8 +249,8 @@ func makeItemID(workspaceID, blockID string) string {
func (ws *Server) addListener(wsSession *websocketSession, command *WebsocketCommand) {
workspaceID, err := ws.getAuthenticatedWorkspaceID(wsSession, command)
if err != nil {
log.Printf("addListener: NOT AUTHENTICATED, ERROR: %v", err)
sendError(wsSession.client, "not authenticated")
ws.logger.Error("addListener: NOT AUTHENTICATED", mlog.Err(err))
ws.sendError(wsSession.client, "not authenticated")
return
}
@@ -272,8 +287,8 @@ func (ws *Server) removeListener(client *websocket.Conn) {
func (ws *Server) removeListenerFromBlocks(wsSession *websocketSession, command *WebsocketCommand) {
workspaceID, err := ws.getAuthenticatedWorkspaceID(wsSession, command)
if err != nil {
log.Printf("addListener: NOT AUTHENTICATED, ERROR: %v", err)
sendError(wsSession.client, "not authenticated")
ws.logger.Error("addListener: NOT AUTHENTICATED", mlog.Err(err))
ws.sendError(wsSession.client, "not authenticated")
return
}
@@ -300,14 +315,14 @@ func (ws *Server) removeListenerFromBlocks(wsSession *websocketSession, command
ws.mu.Unlock()
}
func sendError(conn *websocket.Conn, message string) {
func (ws *Server) sendError(conn *websocket.Conn, message string) {
errorMsg := ErrorMsg{
Error: message,
}
err := conn.WriteJSON(errorMsg)
if err != nil {
log.Printf("sendError error: %v", err)
ws.logger.Error("sendError error", mlog.Err(err))
conn.Close()
}
}
@@ -372,7 +387,10 @@ func (ws *Server) BroadcastBlockChange(workspaceID string, block model.Block) {
for _, blockID := range blockIDsToNotify {
listeners := ws.getListeners(workspaceID, blockID)
log.Printf("%d listener(s) for blockID: %s", len(listeners), blockID)
ws.logger.Debug("listener(s) for blockID",
mlog.Int("listener_count", len(listeners)),
mlog.String("blockID", blockID),
)
message := UpdateMsg{
Action: "UPDATE_BLOCK",
@@ -388,11 +406,15 @@ func (ws *Server) BroadcastBlockChange(workspaceID string, block model.Block) {
if listeners != nil {
for _, listener := range listeners {
log.Printf("Broadcast change, workspaceID: %s, blockID: %s, remoteAddr: %s", workspaceID, blockID, listener.RemoteAddr())
ws.logger.Debug("Broadcast change",
mlog.String("workspaceID", workspaceID),
mlog.String("blockID", blockID),
mlog.Stringer("remoteAddr", listener.RemoteAddr()),
)
err := listener.WriteJSON(message)
if err != nil {
log.Printf("broadcast error: %v", err)
ws.logger.Error("broadcast error", mlog.Err(err))
listener.Close()
}
}