diff --git a/app/server.go b/app/server.go index 93b2ac9a58..9e0a5cb412 100644 --- a/app/server.go +++ b/app/server.go @@ -17,7 +17,6 @@ import ( "sync/atomic" "time" - "github.com/gorilla/handlers" "github.com/gorilla/mux" "github.com/pkg/errors" "github.com/rs/cors" @@ -371,14 +370,6 @@ var corsAllowedMethods = []string{ "DELETE", } -type RecoveryLogger struct { -} - -func (rl *RecoveryLogger) Println(i ...interface{}) { - mlog.Error("Please check the std error output for the stack trace") - mlog.Error(fmt.Sprint(i...)) -} - // golang.org/x/crypto/acme/autocert/autocert.go func handleHTTPRedirect(w http.ResponseWriter, r *http.Request) { if r.Method != "GET" && r.Method != "HEAD" { @@ -436,11 +427,17 @@ func (s *Server) Start() error { handler = rateLimiter.RateLimitHandler(handler) } + // Creating a logger for logging errors from http.Server at error level + errStdLog, err := s.Log.StdLogAt(mlog.LevelError, mlog.String("source", "httpserver")) + if err != nil { + return err + } + s.Server = &http.Server{ - Handler: handlers.RecoveryHandler(handlers.RecoveryLogger(&RecoveryLogger{}), handlers.PrintRecoveryStack(true))(handler), + Handler: handler, ReadTimeout: time.Duration(*s.Config().ServiceSettings.ReadTimeout) * time.Second, WriteTimeout: time.Duration(*s.Config().ServiceSettings.WriteTimeout) * time.Second, - ErrorLog: s.Log.StdLog(mlog.String("source", "httpserver")), + ErrorLog: errStdLog, } addr := *s.Config().ServiceSettings.ListenAddress diff --git a/app/server_test.go b/app/server_test.go index 4ab34b7a31..6012cb0af9 100644 --- a/app/server_test.go +++ b/app/server_test.go @@ -4,9 +4,13 @@ package app import ( + "bufio" "crypto/tls" + "github.com/mattermost/mattermost-server/mlog" + "io/ioutil" "net" "net/http" + "os" "path" "strconv" "strings" @@ -207,3 +211,76 @@ func checkEndpoint(t *testing.T, client *http.Client, url string, expectedStatus return nil } + +func TestPanicLog(t *testing.T) { + // Creating a temp file to collect logs + tmpfile, err := ioutil.TempFile("", "mlog") + if err != nil { + require.NoError(t, err) + } + + defer func() { + require.NoError(t, tmpfile.Close()) + require.NoError(t, os.Remove(tmpfile.Name())) + }() + + // Creating logger to log to console and temp file + logger := mlog.NewLogger(&mlog.LoggerConfiguration{ + EnableConsole: true, + ConsoleJson: true, + EnableFile: true, + FileLocation: tmpfile.Name(), + FileLevel: mlog.LevelInfo, + }) + + // Creating a server with logger + s, err := NewServer(SetLogger(logger)) + require.NoError(t, err) + + // Route for just panicing + s.Router.HandleFunc("/panic", func(writer http.ResponseWriter, request *http.Request) { + s.Log.Info("inside panic handler") + panic("log this panic") + }) + + s.UpdateConfig(func(cfg *model.Config) { *cfg.ServiceSettings.ListenAddress = ":0" }) + serverErr := s.Start() + require.NoError(t, serverErr) + + // Calling panic route + tr := &http.Transport{ + TLSClientConfig: &tls.Config{InsecureSkipVerify: true}, + } + + client := &http.Client{Transport: tr} + client.Get("https://localhost:" + strconv.Itoa(s.ListenAddr.Port) + "/panic") + + err = s.Shutdown() + require.NoError(t, err) + + // Checking whether panic was logged + var panicLogged = false + var infoLogged = false + + _, err = tmpfile.Seek(0, 0) + require.NoError(t, err) + + scanner := bufio.NewScanner(tmpfile) + for scanner.Scan() { + if !infoLogged && strings.Contains(scanner.Text(), "inside panic handler") { + infoLogged = true + } + if strings.Contains(scanner.Text(), "log this panic") { + panicLogged = true + break + } + } + + if !infoLogged { + t.Error("Info log line was supposed to be logged") + } + + if !panicLogged { + t.Error("Panic was supposed to be logged") + } +} diff --git a/mlog/log.go b/mlog/log.go index dd35a30750..a2945046fe 100644 --- a/mlog/log.go +++ b/mlog/log.go @@ -127,6 +127,11 @@ func (l *Logger) StdLog(fields ...Field) *log.Logger { return zap.NewStdLog(l.With(fields...).zap.WithOptions(getStdLogOption())) } +// StdLogAt returns *log.Logger which writes to supplied zap logger at required level. +func (l *Logger) StdLogAt(level string, fields ...Field) (*log.Logger, error) { + return zap.NewStdLogAt(l.With(fields...).zap.WithOptions(getStdLogOption()), getZapLevel(level)) +} + // StdLogWriter returns a writer that can be hooked up to the output of a golang standard logger // anything written will be interpreted as log entries accordingly func (l *Logger) StdLogWriter() io.Writer {