Commit 7961599b authored by Corey Hulen's avatar Corey Hulen Committed by Harrison Healey

PLT-4357 adding performance monitoring (#4622)

* WIP

* WIP

* Adding metrics collection

* updating vendor packages

* Adding metrics to config

* Adding admin console page for perf monitoring

* Updating glide

* switching to tylerb/graceful
parent e033dcce
......@@ -208,6 +208,7 @@ ifeq ($(BUILD_ENTERPRISE_READY),true)
$(GO) test $(GOFLAGS) -run=$(TESTS) -covermode=count -c ./enterprise/emoji && ./emoji.test -test.v -test.timeout=120s -test.coverprofile=cemoji.out || exit 1
$(GO) test $(GOFLAGS) -run=$(TESTS) -covermode=count -c ./enterprise/saml && ./saml.test -test.v -test.timeout=60s -test.coverprofile=csaml.out || exit 1
$(GO) test $(GOFLAGS) -run=$(TESTS) -covermode=count -c ./enterprise/cluster && ./cluster.test -test.v -test.timeout=60s -test.coverprofile=ccluster.out || exit 1
$(GO) test $(GOFLAGS) -run=$(TESTS) -covermode=count -c ./enterprise/metrics && ./metrics.test -test.v -test.timeout=60s -test.coverprofile=cmetrics.out || exit 1
$(GO) test $(GOFLAGS) -run=$(TESTS) -covermode=count -c ./enterprise/account_migration && ./account_migration.test -test.v -test.timeout=60s -test.coverprofile=caccount_migration.out || exit 1
tail -n +2 cldap.out >> ecover.out
......@@ -216,14 +217,16 @@ ifeq ($(BUILD_ENTERPRISE_READY),true)
tail -n +2 cemoji.out >> ecover.out
tail -n +2 csaml.out >> ecover.out
tail -n +2 ccluster.out >> ecover.out
tail -n +2 caccount_migration.out >> ecover.out
rm -f cldap.out ccompliance.out cmfa.out cemoji.out csaml.out ccluster.out caccount_migration.out
tail -n +2 cmetrics.out >> ecover.out
tail -n +2 caccount_migration.out >> ecover.out
rm -f cldap.out ccompliance.out cmfa.out cemoji.out csaml.out ccluster.out cmetrics.out caccount_migration.out
rm -r ldap.test
rm -r compliance.test
rm -r mfa.test
rm -r emoji.test
rm -r saml.test
rm -r cluster.test
rm -r metrics.test
rm -r account_migration.test
rm -f config/*.crt
rm -f config/*.key
......
......@@ -176,6 +176,14 @@ func saveConfig(c *Context, w http.ResponseWriter, r *http.Request) {
utils.SaveConfig(utils.CfgFileName, cfg)
utils.LoadConfig(utils.CfgFileName)
if einterfaces.GetMetricsInterface() != nil {
if *utils.Cfg.MetricsSettings.Enable {
einterfaces.GetMetricsInterface().StartServer()
} else {
einterfaces.GetMetricsInterface().StopServer()
}
}
// Future feature is to sync the configuration files
// if einterfaces.GetClusterInterface() != nil {
// err := einterfaces.GetClusterInterface().ConfigChanged(cfg, oldCfg, true)
......
......@@ -36,7 +36,7 @@ func SetupEnterprise() *TestHelper {
*utils.Cfg.RateLimitSettings.Enable = false
utils.DisableDebugLogForTest()
utils.License.Features.SetDefaults()
NewServer(false)
NewServer()
StartServer()
utils.InitHTML()
InitApi()
......@@ -57,7 +57,7 @@ func Setup() *TestHelper {
utils.Cfg.TeamSettings.MaxUsersPerTeam = 50
*utils.Cfg.RateLimitSettings.Enable = false
utils.DisableDebugLogForTest()
NewServer(false)
NewServer()
StartServer()
InitApi()
utils.EnableDebugLogForTest()
......
......@@ -9,6 +9,7 @@ import (
"net/http"
"net/url"
"strings"
"time"
l4g "github.com/alecthomas/log4go"
"github.com/gorilla/mux"
......@@ -103,6 +104,7 @@ type handler struct {
}
func (h handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
now := time.Now()
l4g.Debug("%v", r.URL.Path)
c := &Context{}
......@@ -228,6 +230,10 @@ func (h handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
if h.isApi {
w.WriteHeader(c.Err.StatusCode)
w.Write([]byte(c.Err.ToJson()))
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementHttpError()
}
} else {
if c.Err.StatusCode == http.StatusUnauthorized {
http.Redirect(w, r, c.GetTeamURL()+"/?redirect="+url.QueryEscape(r.URL.Path), http.StatusTemporaryRedirect)
......@@ -235,6 +241,16 @@ func (h handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
RenderWebError(c.Err, w, r)
}
}
}
if h.isApi && einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementHttpRequest()
if r.URL.Path != model.API_URL_SUFFIX+"/users/websocket" {
elapsed := float64(time.Since(now)) / float64(time.Second)
einterfaces.GetMetricsInterface().ObserveHttpRequestDuration(elapsed)
}
}
}
......
......@@ -21,6 +21,7 @@ import (
l4g "github.com/alecthomas/log4go"
"github.com/gorilla/mux"
"github.com/mattermost/platform/einterfaces"
"github.com/mattermost/platform/model"
"github.com/mattermost/platform/store"
"github.com/mattermost/platform/utils"
......@@ -146,6 +147,10 @@ func CreatePost(c *Context, post *model.Post, triggerWebhooks bool) (*model.Post
rpost = result.Data.(*model.Post)
}
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementPostCreate()
}
if len(post.FileIds) > 0 {
// There's a rare bug where the client sends up duplicate FileIds so protect against that
post.FileIds = utils.RemoveDuplicatesFromStringArray(post.FileIds)
......@@ -155,6 +160,10 @@ func CreatePost(c *Context, post *model.Post, triggerWebhooks bool) (*model.Post
l4g.Error(utils.T("api.post.create_post.attach_files.error"), post.Id, post.FileIds, c.Session.UserId, result.Err)
}
}
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementPostFileAttachment(len(post.FileIds))
}
}
handlePostEvents(c, rpost, triggerWebhooks)
......@@ -869,6 +878,10 @@ func sendNotificationEmail(c *Context, post *model.Post, user *model.User, chann
if err := utils.SendMail(user.Email, html.UnescapeString(subject), bodyPage.Render()); err != nil {
l4g.Error(utils.T("api.post.send_notifications_and_forget.send.error"), user.Email, err)
}
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementPostSentEmail()
}
}
func getMessageForNotification(post *model.Post, translateFunc i18n.TranslateFunc) string {
......@@ -959,6 +972,9 @@ func sendPushNotification(post *model.Post, user *model.User, channel *model.Cha
tmpMessage := *model.PushNotificationFromJson(strings.NewReader(msg.ToJson()))
tmpMessage.SetDeviceIdAndPlatform(session.DeviceId)
sendToPushProxy(tmpMessage)
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementPostSentPush()
}
}
}
......
......@@ -7,7 +7,6 @@ import (
"crypto/tls"
"net"
"net/http"
"net/http/pprof"
"strings"
"time"
......@@ -37,20 +36,7 @@ const TIME_TO_WAIT_FOR_CONNECTIONS_TO_CLOSE_ON_SERVER_SHUTDOWN = time.Second
var Srv *Server
func AttachProfiler(router *mux.Router) {
router.HandleFunc("/debug/pprof/", pprof.Index)
router.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
router.HandleFunc("/debug/pprof/profile", pprof.Profile)
router.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
// Manually add support for paths linked to by index page at /debug/pprof/
router.Handle("/debug/pprof/goroutine", pprof.Handler("goroutine"))
router.Handle("/debug/pprof/heap", pprof.Handler("heap"))
router.Handle("/debug/pprof/threadcreate", pprof.Handler("threadcreate"))
router.Handle("/debug/pprof/block", pprof.Handler("block"))
}
func NewServer(enableProfiler bool) {
func NewServer() {
l4g.Info(utils.T("api.server.new_server.init.info"))
......@@ -58,10 +44,6 @@ func NewServer(enableProfiler bool) {
Srv.Store = store.NewSqlStore()
Srv.Router = mux.NewRouter()
if enableProfiler {
AttachProfiler(Srv.Router)
l4g.Info("Enabled HTTP Profiler")
}
Srv.Router.NotFoundHandler = http.HandlerFunc(Handle404)
}
......
......@@ -469,6 +469,9 @@ func login(c *Context, w http.ResponseWriter, r *http.Request) {
c.LogAuditWithUserId(user.Id, "failure")
c.Err = result.Err
c.Err.StatusCode = http.StatusBadRequest
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementLoginFail()
}
return
} else {
user = result.Data.(*model.User)
......@@ -479,6 +482,9 @@ func login(c *Context, w http.ResponseWriter, r *http.Request) {
if user, err = getUserForLogin(loginId, ldapOnly); err != nil {
c.LogAudit("failure")
c.Err = err
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementLoginFail()
}
return
}
......@@ -489,10 +495,16 @@ func login(c *Context, w http.ResponseWriter, r *http.Request) {
if user, err = authenticateUser(user, password, mfaToken); err != nil {
c.LogAuditWithUserId(user.Id, "failure")
c.Err = err
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementLoginFail()
}
return
}
c.LogAuditWithUserId(user.Id, "success")
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementLogin()
}
doLogin(c, w, r, user, deviceId)
if c.Err != nil {
......
......@@ -7,6 +7,7 @@ import (
"fmt"
"time"
"github.com/mattermost/platform/einterfaces"
"github.com/mattermost/platform/model"
"github.com/mattermost/platform/utils"
......@@ -111,6 +112,12 @@ func (c *WebConn) writePump() {
return
}
if msg.EventType() == model.WEBSOCKET_EVENT_POSTED {
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().IncrementPostBroadcast()
}
}
case <-ticker.C:
c.WebSocket.SetWriteDeadline(time.Now().Add(WRITE_WAIT))
if err := c.WebSocket.WriteMessage(websocket.PingMessage, []byte{}); err != nil {
......
......@@ -228,6 +228,10 @@
"InterNodeListenAddress": ":8075",
"InterNodeUrls": []
},
"MetricsSettings": {
"Enable": false,
"ListenAddress": ":8067"
},
"WebrtcSettings": {
"Enable": false,
"GatewayWebsocketUrl": "",
......
// Copyright (c) 2015 Mattermost, Inc. All Rights Reserved.
// See License.txt for license information.
package einterfaces
type MetricsInterface interface {
StartServer()
StopServer()
IncrementPostCreate()
IncrementPostSentEmail()
IncrementPostSentPush()
IncrementPostBroadcast()
IncrementPostFileAttachment(count int)
IncrementHttpRequest()
IncrementHttpError()
ObserveHttpRequestDuration(elapsed float64)
IncrementLogin()
IncrementLoginFail()
}
var theMetricsInterface MetricsInterface
func RegisterMetricsInterface(newInterface MetricsInterface) {
theMetricsInterface = newInterface
}
func GetMetricsInterface() MetricsInterface {
return theMetricsInterface
}
hash: 21760a0ad0c2c37b28af04c042b714a1f1d0370ee1959e4ec90a1168d011cb0f
updated: 2016-11-16T16:57:00.442024925-05:00
hash: 6356cb81d6e15717a3ca6e205184d4144bf7087feebeb19d24ff72b20c65b985
updated: 2016-11-22T09:00:05.599031729-08:00
imports:
- name: github.com/alecthomas/log4go
version: e5dc62318d9bd58682f1dceb53a4b24e8253682f
- name: github.com/braintree/manners
version: 0b5e6b2c2843f4c83c2a40f96980b09cf4af733c
- name: github.com/beorn7/perks
version: 4c0e84591b9aa9e6dcfdf3e020114cd81f89d5f9
subpackages:
- quantile
- name: github.com/dgryski/dgoogauth
version: 96977cbd42e27be71f9f731db6634123de7e861a
- name: github.com/disintegration/imaging
......@@ -25,6 +27,10 @@ imports:
subpackages:
- raster
- truetype
- name: github.com/golang/protobuf
version: 8ee79997227bf9b34611aee7946ae64735e6fd93
subpackages:
- proto
- name: github.com/gorilla/context
version: 08b5f424b9271eedf6f9f0ce86cb9396ed337a42
- name: github.com/gorilla/handlers
......@@ -49,8 +55,12 @@ imports:
- gf256
- qr
- qr/coding
- name: github.com/matttproud/golang_protobuf_extensions
version: 3247c84500bff8d9fb6d579d800f20b3e091582c
subpackages:
- pbutil
- name: github.com/miekg/dns
version: 58f52c57ce9df13460ac68200cef30a008b9c468
version: 271c58e0c14f552178ea321a545ff9af38930f39
- name: github.com/minio/minio-go
version: c040578255dbb1a1f41cbdc5bd944de4140b4149
subpackages:
......@@ -69,6 +79,20 @@ imports:
version: 172fbbbb329cf7e031dd3ab35766186fc2081eab
- name: github.com/pborman/uuid
version: a97ce2ca70fa5a848076093f05e639a89ca34d06
- name: github.com/prometheus/client_golang
version: c5b7fccd204277076155f10851dad72b76a49317
subpackages:
- prometheus
- name: github.com/prometheus/client_model
version: fa8ad6fec33561be4280a8f0514318c79d7f6cb6
subpackages:
- go
- name: github.com/prometheus/common
version: 0d5de9d6d8629cb8bee6d4674da4127cd8b615a3
subpackages:
- expfmt
- name: github.com/prometheus/procfs
version: abf152e5f3e97f2fafac028d2cc06c1feb87ffa5
- name: github.com/rsc/letsencrypt
version: 76104d26167d38b6a0010f42bfc8ec5487742e8b
- name: github.com/rwcarlsen/goexif
......@@ -81,9 +105,9 @@ imports:
- name: github.com/segmentio/backo-go
version: 204274ad699c0983a70203a566887f17a717fef4
- name: github.com/tylerb/graceful
version: 50a48b6e73fcc75b45e22c05b79629a67c79e938
version: 4df1190835320af7076dfcf27b3d071fd3612caf
- name: github.com/xenolf/lego
version: 9f86882f775f75f69617ecc160e39f4e0b7ae27f
version: 0abbd738a45af51595a214c52b02b18d16974f19
subpackages:
- acme
- name: github.com/xtgo/uuid
......
......@@ -4,8 +4,6 @@ import:
version: 172fbbbb329cf7e031dd3ab35766186fc2081eab
- package: github.com/alecthomas/log4go
version: e5dc62318d9bd58682f1dceb53a4b24e8253682f
- package: github.com/braintree/manners
version: 0.4.0
- package: github.com/dgryski/dgoogauth
version: 96977cbd42e27be71f9f731db6634123de7e861a
- package: github.com/disintegration/imaging
......@@ -66,4 +64,25 @@ import:
- package: github.com/rsc/letsencrypt
version: 76104d26167d38b6a0010f42bfc8ec5487742e8b
- package: github.com/minio/minio-go
version: v2.0.2
version: 2.0.2
- package: github.com/prometheus/client_golang
version: v0.8.0
subpackages:
- prometheus
- package: github.com/beorn7/perks
subpackages:
- quantile
- package: github.com/golang/protobuf
subpackages:
- proto
- package: github.com/prometheus/client_model
subpackages:
- go
- package: github.com/prometheus/common
subpackages:
- expfmt
- package: github.com/matttproud/golang_protobuf_extensions
version: v1.0.0
subpackages:
- pbutil
- package: github.com/prometheus/procfs
......@@ -2659,6 +2659,14 @@
"id": "ent.cluster.save_config.error",
"translation": "System Console is set to read-only when High Availability is enabled."
},
{
"id": "ent.metrics.starting.info",
"translation": "Metrics and profiling server is listening on %v"
},
{
"id": "ent.metrics.stopping.info",
"translation": "Metrics and profiling server is stopping on %v"
},
{
"id": "ent.cluster.starting.info",
"translation": "Cluster internode communication is listening on %v with hostname=%v id=%v"
......
......@@ -14,7 +14,6 @@ import (
"os/exec"
"os/signal"
"runtime"
"runtime/pprof"
"strconv"
"strings"
"syscall"
......@@ -84,10 +83,6 @@ var flagChannelHeader string
var flagChannelPurpose string
var flagUserSetInactive bool
var flagImportArchive string
var flagCpuProfile bool
var flagMemProfile bool
var flagBlockProfile bool
var flagHttpProfiler bool
func doLoadConfig(filename string) (err string) {
defer func() {
......@@ -127,26 +122,7 @@ func main() {
cmdUpdateDb30()
if flagCpuProfile {
f, err := os.Create(utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".cpu.prof")
if err != nil {
l4g.Error("Error creating cpu profile log: " + err.Error())
}
l4g.Info("CPU Profiler is logging to " + utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".cpu.prof")
pprof.StartCPUProfile(f)
}
if flagBlockProfile {
l4g.Info("Block Profiler is logging to " + utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".blk.prof")
runtime.SetBlockProfileRate(1)
}
if flagMemProfile {
l4g.Info("Memory Profiler is logging to " + utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".mem.prof")
}
api.NewServer(flagHttpProfiler)
api.NewServer()
api.InitApi()
web.InitWeb()
......@@ -182,6 +158,10 @@ func main() {
einterfaces.GetClusterInterface().StartInterNodeCommunication()
}
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().StartServer()
}
// wait for kill signal before attempting to gracefully shutdown
// the running service
c := make(chan os.Signal)
......@@ -192,38 +172,11 @@ func main() {
einterfaces.GetClusterInterface().StopInterNodeCommunication()
}
api.StopServer()
if flagCpuProfile {
l4g.Info("Closing CPU Profiler")
pprof.StopCPUProfile()
}
if flagBlockProfile {
f, err := os.Create(utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".blk.prof")
if err != nil {
l4g.Error("Error creating block profile log: " + err.Error())
}
l4g.Info("Writing Block Profiler to: " + utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".blk.prof")
pprof.Lookup("block").WriteTo(f, 0)
f.Close()
runtime.SetBlockProfileRate(0)
if einterfaces.GetMetricsInterface() != nil {
einterfaces.GetMetricsInterface().StopServer()
}
if flagMemProfile {
f, err := os.Create(utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".mem.prof")
if err != nil {
l4g.Error("Error creating memory profile file: " + err.Error())
}
l4g.Info("Writing Memory Profiler to: " + utils.GetLogFileLocation(utils.Cfg.LogSettings.FileLocation) + ".mem.prof")
runtime.GC()
if err := pprof.WriteHeapProfile(f); err != nil {
l4g.Error("Error creating memory profile: " + err.Error())
}
f.Close()
}
api.StopServer()
}