Adding structuredLogging check and fix inconsistencies (#13370)

* Adding structuredLogging check and fix inconsistencies * Addressing PR review comments * Addressing PR review comments * Addressing PR review comments * Addressing PR review comments * Addressing PR review comments
2025-02-25 18:55:24 -06:00 · 2019-12-16 13:57:21 +01:00
parent fd0a3a687d
commit b8ef62e502
10 changed files with 43 additions and 21 deletions
--- a/2
+++ b/2
@@ -454,7 +454,7 @@ vet: ## Run mattermost go vet specific checks
 		exit 1; \
 	fi; \

-	$(GO) vet -vettool=$(GOPATH)/bin/mattermost-govet -license ./...
+	$(GO) vet -vettool=$(GOPATH)/bin/mattermost-govet -license -structuredLogging ./...
 ifeq ($(BUILD_ENTERPRISE_READY),true)
 	$(GO) vet -vettool=$(GOPATH)/bin/mattermost-govet -enterpriseLicense ./enterprise/...
 endif
--- a/api4/system_test.go
+++ b/api4/system_test.go
@@ -8,6 +8,7 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"os"
+	"strconv"
 	"strings"
 	"testing"
 	"time"
@@ -242,7 +243,7 @@ func TestGetLogs(t *testing.T) {
 	Client := th.Client

 	for i := 0; i < 20; i++ {
-		mlog.Info(fmt.Sprint(i))
+		mlog.Info(strconv.Itoa(i))
 	}

 	logs, resp := th.SystemAdminClient.GetLogs(0, 10)
--- a/app/command.go
+++ b/app/command.go
@@ -4,7 +4,6 @@
 package app

 import (
-	"fmt"
 	"io"
 	"io/ioutil"
 	"net/http"
@@ -272,7 +271,7 @@ func (a *App) tryExecuteCustomCommand(args *model.CommandArgs, trigger string, m
 		return nil, nil, nil
 	}

-	mlog.Debug(fmt.Sprintf(utils.T("api.command.execute_command.debug"), trigger, args.UserId))
+	mlog.Debug("Executing command", mlog.String("command", trigger), mlog.String("user_id", args.UserId))

 	p := url.Values{}
 	p.Set("token", cmd.Token)
--- a/app/email_batching.go
+++ b/app/email_batching.go
@@ -71,7 +71,7 @@ func NewEmailBatchingJob(s *Server, bufferSize int) *EmailBatchingJob {
 }

 func (job *EmailBatchingJob) Start() {
-	mlog.Debug(fmt.Sprintf("Email batching job starting. Checking for pending emails every %v seconds.", *job.server.Config().EmailSettings.EmailBatchingInterval))
+	mlog.Debug("Email batching job starting. Checking for pending emails periodically.", mlog.Int("interval_in_seconds", *job.server.Config().EmailSettings.EmailBatchingInterval))
 	newTask := model.CreateRecurringTask(EMAIL_BATCHING_TASK_NAME, job.CheckPendingEmails, time.Duration(*job.server.Config().EmailSettings.EmailBatchingInterval)*time.Second)

 	job.taskMutex.Lock()
@@ -107,7 +107,7 @@ func (job *EmailBatchingJob) CheckPendingEmails() {
 	// without actually sending emails
 	job.checkPendingNotifications(time.Now(), job.server.sendBatchedEmailNotification)

-	mlog.Debug(fmt.Sprintf("Email batching job ran. %v user(s) still have notifications pending.", len(job.pendingNotifications)))
+	mlog.Debug("Email batching job ran. Some users still have notifications pending.", mlog.Int("number_of_users", len(job.pendingNotifications)))
 }

 func (job *EmailBatchingJob) handleNewNotifications() {
--- a/app/file.go
+++ b/app/file.go
@@ -145,10 +145,11 @@ func (a *App) getInfoForFilename(post *model.Post, teamId, channelId, userId, ol
 	data, err := a.ReadFile(path)
 	if err != nil {
 		mlog.Error(
-			fmt.Sprintf("File not found when migrating post to use FileInfos, err=%v", err),
+			"File not found when migrating post to use FileInfos",
 			mlog.String("post_id", post.Id),
 			mlog.String("filename", filename),
 			mlog.String("path", path),
+			mlog.Err(err),
 		)
 		return nil
 	}
--- a/app/ldap.go
+++ b/app/ldap.go
@@ -4,7 +4,6 @@
 package app

 import (
-	"fmt"
 	"net/http"

 	"github.com/mattermost/mattermost-server/v5/mlog"
@@ -19,7 +18,7 @@ func (a *App) SyncLdap() {
 			if ldapI := a.Ldap; ldapI != nil {
 				ldapI.StartSynchronizeJob(false)
 			} else {
-				mlog.Error(fmt.Sprintf("%v", model.NewAppError("SyncLdap", "ent.ldap.disabled.app_error", nil, "", http.StatusNotImplemented).Error()))
+				mlog.Error("Not executing ldap sync because ldap is not available")
 			}
 		}
 	})
--- a/app/server.go
+++ b/app/server.go
@@ -215,8 +215,20 @@ func NewServer(options ...Option) (*Server, error) {
 		}
 	})

-	mlog.Info(fmt.Sprintf("Current version is %v (%v/%v/%v/%v)", model.CurrentVersion, model.BuildNumber, model.BuildDate, model.BuildHash, model.BuildHashEnterprise))
-	mlog.Info(fmt.Sprintf("Enterprise Enabled: %v", model.BuildEnterpriseReady))
+	logCurrentVersion := fmt.Sprintf("Current version is %v (%v/%v/%v/%v)", model.CurrentVersion, model.BuildNumber, model.BuildDate, model.BuildHash, model.BuildHashEnterprise)
+	mlog.Info(
+		logCurrentVersion,
+		mlog.String("current_version", model.CurrentVersion),
+		mlog.String("build_number", model.BuildNumber),
+		mlog.String("build_date", model.BuildDate),
+		mlog.String("build_hash", model.BuildHash),
+		mlog.String("build_hash_enterprise", model.BuildHashEnterprise),
+	)
+	if model.BuildEnterpriseReady == "true" {
+		mlog.Info("Enterprise Build", mlog.Bool("enterprise_build", true))
+	} else {
+		mlog.Info("Team Edition Build", mlog.Bool("enterprise_build", false))
+	}

 	pwd, _ := os.Getwd()
 	mlog.Info("Printing current working", mlog.String("directory", pwd))
@@ -505,7 +517,8 @@ func (s *Server) Start() error {
 	}
 	s.ListenAddr = listener.Addr().(*net.TCPAddr)

-	mlog.Info(fmt.Sprintf("Server is listening on %v", listener.Addr().String()))
+	logListeningPort := fmt.Sprintf("Server is listening on %v", listener.Addr().String())
+	mlog.Info(logListeningPort, mlog.String("address", listener.Addr().String()))

 	// Migration from old let's encrypt library
 	if *s.Config().ServiceSettings.UseLetsEncrypt {
--- a/i18n/en.json
+++ b/i18n/en.json
@@ -431,10 +431,6 @@
    "id": "api.command.execute_command.create_post_failed.app_error",
    "translation": "Command '{{.Trigger}}' failed to post response. Please contact your System Administrator."
  },
-  {
-    "id": "api.command.execute_command.debug",
-    "translation": "Executing cmd=%v userId=%v"
-  },
  {
    "id": "api.command.execute_command.failed.app_error",
    "translation": "Command with a trigger of '{{.Trigger}}' failed"
--- a/store/sqlstore/post_store.go
+++ b/store/sqlstore/post_store.go
@@ -107,7 +107,7 @@ func (s *SqlPostStore) Save(post *model.Post) (*model.Post, *model.AppError) {
 		}
 	} else {
 		if count, err := s.GetMaster().SelectInt("SELECT COUNT(*) FROM Posts WHERE RootId = :Id", map[string]interface{}{"Id": post.Id}); err != nil {
-			mlog.Error(fmt.Sprintf("Error fetching post's thread: %v", err.Error()))
+			mlog.Error("Error fetching post's thread.", mlog.Err(err))
 		} else {
 			post.ReplyCount = count
 		}
--- a/wsapi/websocket_handler.go
+++ b/wsapi/websocket_handler.go
@@ -4,7 +4,6 @@
 package wsapi

 import (
-	"fmt"
 	"net/http"

 	"github.com/mattermost/mattermost-server/v5/app"
@@ -23,11 +22,18 @@ type webSocketHandler struct {
 }

 func (wh webSocketHandler) ServeWebSocket(conn *app.WebConn, r *model.WebSocketRequest) {
-	mlog.Debug(fmt.Sprintf("websocket: %s", r.Action))
+	mlog.Debug("Websocket request", mlog.String("action", r.Action))

 	session, sessionErr := wh.app.GetSession(conn.GetSessionToken())
 	if sessionErr != nil {
-		mlog.Error(fmt.Sprintf("%v:%v seq=%v uid=%v %v [details: %v]", "websocket", r.Action, r.Seq, conn.UserId, sessionErr.SystemMessage(utils.T), sessionErr.Error()))
+		mlog.Error(
+			"websocket session error",
+			mlog.String("action", r.Action),
+			mlog.Int64("seq", r.Seq),
+			mlog.String("user_id", conn.UserId),
+			mlog.String("error_message", sessionErr.SystemMessage(utils.T)),
+			mlog.Err(sessionErr),
+		)
 		sessionErr.DetailedError = ""
 		errResp := model.NewWebSocketError(r.Seq, sessionErr)

@@ -43,7 +49,14 @@ func (wh webSocketHandler) ServeWebSocket(conn *app.WebConn, r *model.WebSocketR
 	var err *model.AppError

 	if data, err = wh.handlerFunc(r); err != nil {
-		mlog.Error(fmt.Sprintf("%v:%v seq=%v uid=%v %v [details: %v]", "websocket", r.Action, r.Seq, r.Session.UserId, err.SystemMessage(utils.T), err.DetailedError))
+		mlog.Error(
+			"websocket request handling error",
+			mlog.String("action", r.Action),
+			mlog.Int64("seq", r.Seq),
+			mlog.String("user_id", conn.UserId),
+			mlog.String("error_message", err.SystemMessage(utils.T)),
+			mlog.Err(err),
+		)
 		err.DetailedError = ""
 		errResp := model.NewWebSocketError(r.Seq, err)