instrument server with prometheus metrics; fixes #267

Signed-off-by: Denys Smirnov <[email protected]>

cmd/bblfshd/main.go

@@ -17,6 +17,7 @@ import (
 	"github.com/bblfsh/bblfshd/daemon"
 	"github.com/bblfsh/bblfshd/runtime"
 
+	"github.com/prometheus/client_golang/prometheus/promhttp"
 	"github.com/sirupsen/logrus"
 	jaegercfg "github.com/uber/jaeger-client-go/config"
 
@@ -53,6 +54,9 @@ var (
 		enabled *bool
 		address *string
 	}
+	metrics struct {
+		address *string
+	}
 	cmd *flag.FlagSet
 
 	usrListener net.Listener
@@ -75,6 +79,7 @@ func init() {
 	log.fields = cmd.String("log-fields", "", "extra fields to add to every log line in json format.")
 	pprof.enabled = cmd.Bool("profiler", false, "run profiler http endpoint (pprof).")
 	pprof.address = cmd.String("profiler-address", ":6060", "profiler address to listen on.")
+	metrics.address = cmd.String("metrics-address", ":2112", "metrics address to listen on.")
 	cmd.Parse(os.Args[1:])
 
 	buildLogger()
@@ -118,6 +123,14 @@ func main() {
 			}
 		}()
 	}
+	if *metrics.address != "" {
+		logrus.Infof("running metrics on %s", *metrics.address)
+		go func() {
+			if err := http.ListenAndServe(*metrics.address, promhttp.Handler()); err != nil {
+				logrus.Errorf("cannot start metrics: %v", err)
+			}
+		}()
+	}
 
 	if os.Getenv("JAEGER_AGENT_HOST") != "" {
 		c, err := jaegercfg.FromEnv()

daemon/daemon.go

@@ -74,6 +74,8 @@ func registerGRPC(d *Daemon) {
 }
 
 func (d *Daemon) InstallDriver(language string, image string, update bool) error {
+	driverInstallCalls.Add(1)
+
 	img, err := runtime.NewDriverImage(image)
 	if err != nil {
 		return ErrRuntime.Wrap(err)
@@ -114,6 +116,8 @@ func (d *Daemon) InstallDriver(language string, image string, update bool) error
 }
 
 func (d *Daemon) RemoveDriver(language string) error {
+	driverRemoveCalls.Add(1)
+
 	img, err := d.getDriverImage(context.TODO(), language)
 	if err != nil {
 		return ErrRuntime.Wrap(err)
@@ -177,11 +181,14 @@ func (d *Daemon) newDriverPool(rctx context.Context, language string, image runt
 	sp, ctx := opentracing.StartSpanFromContext(rctx, "bblfshd.pool.newDriverPool")
 	defer sp.Finish()
 
+	imageName := image.Name()
+	labels := []string{language, imageName}
+
 	dp := NewDriverPool(func(rctx context.Context) (Driver, error) {
 		sp, ctx := opentracing.StartSpanFromContext(rctx, "bblfshd.pool.driverFactory")
 		defer sp.Finish()
 
-		logrus.Debugf("spawning driver instance %q ...", image.Name())
+		logrus.Debugf("spawning driver instance %q ...", imageName)
 
 		opts := d.getDriverInstanceOptions()
 		driver, err := NewDriverInstance(d.runtime, language, image, opts)
@@ -193,13 +200,10 @@ func (d *Daemon) newDriverPool(rctx context.Context, language string, image runt
 			return nil, err
 		}
 
-		logrus.Infof("new driver instance started %s (%s)", image.Name(), driver.Container.ID())
+		logrus.Infof("new driver instance started %s (%s)", imageName, driver.Container.ID())
 		return driver, nil
 	})
-
-	dp.Logger = logrus.WithFields(logrus.Fields{
-		"language": language,
-	})
+	dp.SetLabels(labels)
 
 	if err := dp.Start(ctx); err != nil {
 		return nil, err

daemon/language.go

@@ -3,18 +3,24 @@ package daemon
 import (
 	"strings"
 
+	"github.com/prometheus/client_golang/prometheus"
 	"gopkg.in/src-d/enry.v1"
 )
 
 // GetLanguage detects the language of a file and returns it in a normalized
 // form.
 func GetLanguage(filename string, content []byte) string {
+	totalEnryCalls.Add(1)
+	defer prometheus.NewTimer(enryDetectLatency).ObserveDuration()
+
 	lang := enry.GetLanguage(filename, content)
 	if lang == enry.OtherLanguage {
+		enryOtherResults.Add(1)
 		return lang
 	}
-
-	return normalize(lang)
+	enryLangResults.WithLabelValues(lang).Add(1)
+	lang = normalize(lang)
+	return lang
 }
 
 // normalize maps enry language names to the bblfsh ones.

daemon/metrics.go

@@ -0,0 +1,111 @@
+package daemon
+
+import (
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promauto"
+)
+
+// Enry metrics
+var (
+	totalEnryCalls = promauto.NewCounter(prometheus.CounterOpts{
+		Name: "bblfshd_enry_total",
+		Help: "The total number of calls to Enry to detect the language",
+	})
+	enryLangResults = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "bblfshd_enry_langs",
+		Help: "The total number of Enry results for each programming language",
+	}, []string{"lang"})
+	enryOtherResults  = enryLangResults.WithLabelValues("other")
+	enryDetectLatency = promauto.NewHistogram(prometheus.HistogramOpts{
+		Name: "bblfshd_enry_seconds",
+		Help: "Time spent for detecting the language (seconds)",
+	})
+)
+
+var (
+	driverLabelNames = []string{"lang", "image"}
+)
+
+// Driver Control API metrics
+var (
+	driverInstallCalls = promauto.NewCounter(prometheus.CounterOpts{
+		Name: "bblfshd_driver_install_total",
+		Help: "The total number of calls to install a driver",
+	})
+	driverRemoveCalls = promauto.NewCounter(prometheus.CounterOpts{
+		Name: "bblfshd_driver_remove_total",
+		Help: "The total number of calls to remove a driver",
+	})
+)
+
+// Public API metrics
+var (
+	parseCalls = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "bblfshd_parse_total",
+		Help: "The total number of parse requests",
+	}, []string{"vers"})
+	parseErrors = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "bblfshd_parse_errors",
+		Help: "The total number of failed parse requests",
+	}, []string{"vers"})
+	parseLatency = promauto.NewHistogramVec(prometheus.HistogramOpts{
+		Name: "bblfshd_parse_seconds",
+		Help: "Time spent on parse requests (seconds)",
+	}, []string{"vers"})
+	parseContentSize = promauto.NewHistogramVec(prometheus.HistogramOpts{
+		Name: "bblfshd_parse_bytes",
+		Help: "Size of parsed files",
+	}, []string{"vers"})
+
+	parseCallsV1       = parseCalls.WithLabelValues("v1")
+	parseErrorsV1      = parseErrors.WithLabelValues("v1")
+	parseLatencyV1     = parseLatency.WithLabelValues("v1")
+	parseContentSizeV1 = parseContentSize.WithLabelValues("v1")
+
+	parseCallsV2       = parseCalls.WithLabelValues("v2")
+	parseErrorsV2      = parseErrors.WithLabelValues("v2")
+	parseLatencyV2     = parseLatency.WithLabelValues("v2")
+	parseContentSizeV2 = parseContentSize.WithLabelValues("v2")
+
+	versionCalls = promauto.NewCounter(prometheus.CounterOpts{
+		Name: "bblfshd_version_total",
+		Help: "The total number of version requests",
+	})
+	languagesCalls = promauto.NewCounter(prometheus.CounterOpts{
+		Name: "bblfshd_languages_total",
+		Help: "The total number of supported languages requests",
+	})
+)
+
+// Scaling metrics
+var (
+	driversSpawned = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "bblfshd_driver_spawn",
+		Help: "The total number of driver spawn requests",
+	}, driverLabelNames)
+	driversSpawnErrors = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "bblfshd_driver_spawn_errors",
+		Help: "The total number of errors for driver spawn requests",
+	}, driverLabelNames)
+	driversKilled = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "bblfshd_driver_kill",
+		Help: "The total number of driver kill requests",
+	}, driverLabelNames)
+
+	driversRunning = promauto.NewGaugeVec(prometheus.GaugeOpts{
+		Name: "bblfshd_driver_scaling_total",
+		Help: "The total number of drivers running",
+	}, driverLabelNames)
+	driversIdle = promauto.NewGaugeVec(prometheus.GaugeOpts{
+		Name: "bblfshd_driver_scaling_idle",
+		Help: "The total number of idle drivers",
+	}, driverLabelNames)
+	driversRequests = promauto.NewGaugeVec(prometheus.GaugeOpts{
+		Name: "bblfshd_driver_scaling_load",
+		Help: "The total number of requests waiting for a driver",
+	}, driverLabelNames)
+	driversTarget = promauto.NewGaugeVec(prometheus.GaugeOpts{
+		Name: "bblfshd_driver_scaling_target",
+		Help: "The target number of drivers instances",
+	}, driverLabelNames)
+)

daemon/pool.go

@@ -14,6 +14,7 @@ import (
 
 	"github.com/cenkalti/backoff"
 	"github.com/opentracing/opentracing-go"
+	"github.com/prometheus/client_golang/prometheus"
 	"github.com/sirupsen/logrus"
 
 	"github.com/bblfsh/bblfshd/daemon/protocol"
@@ -157,6 +158,20 @@ type DriverPool struct {
 	exited  atomicInt // drivers exited
 	success atomicInt // requests executed successfully
 	errors  atomicInt // requests failed
+
+	metrics struct {
+		scaling struct {
+			total  prometheus.Gauge
+			idle   prometheus.Gauge
+			load   prometheus.Gauge
+			target prometheus.Gauge
+		}
+		spawn struct {
+			total prometheus.Counter
+			err   prometheus.Counter
+			kill  prometheus.Counter
+		}
+	}
 }
 
 type driverRequest struct {
@@ -176,12 +191,27 @@ type FactoryFunction func(ctx context.Context) (Driver, error)
 // NewDriverPool creates and starts a new DriverPool. It takes as parameters
 // a FactoryFunction, used to instantiate new drivers.
 func NewDriverPool(factory FactoryFunction) *DriverPool {
-	dp := &DriverPool{
+	return &DriverPool{
 		ScalingPolicy: DefaultScalingPolicy(),
 		Logger:        logrus.New(),
 		factory:       factory,
 	}
-	return dp
+}
+
+func (dp *DriverPool) SetLabels(labels []string) {
+	dp.Logger = logrus.WithFields(logrus.Fields{
+		"language": labels[0],
+		"image":    labels[1],
+	})
+
+	dp.metrics.spawn.total = driversSpawned.WithLabelValues(labels...)
+	dp.metrics.spawn.err = driversSpawnErrors.WithLabelValues(labels...)
+	dp.metrics.spawn.kill = driversKilled.WithLabelValues(labels...)
+
+	dp.metrics.scaling.total = driversRunning.WithLabelValues(labels...)
+	dp.metrics.scaling.idle = driversIdle.WithLabelValues(labels...)
+	dp.metrics.scaling.load = driversRequests.WithLabelValues(labels...)
+	dp.metrics.scaling.target = driversTarget.WithLabelValues(labels...)
 }
 
 // Start stats the driver pool.
@@ -267,6 +297,12 @@ func (dp *DriverPool) runPolicy(ctx context.Context) {
 			// TODO(dennwc): policies must never return 0 instances
 			target = 1
 		}
+		if dp.metrics.scaling.total != nil {
+			dp.metrics.scaling.total.Set(float64(total))
+			dp.metrics.scaling.load.Set(float64(load))
+			dp.metrics.scaling.idle.Set(float64(idle))
+			dp.metrics.scaling.target.Set(float64(target))
+		}
 		old := dp.targetSize.Set(target)
 		if old != target {
 			// send a signal to the manager goroutine
@@ -294,6 +330,9 @@ func (dp *DriverPool) spawnOne() {
 	ctx := dp.poolCtx
 	stop := ctx.Done()
 	for {
+		if dp.metrics.spawn.total != nil {
+			dp.metrics.spawn.total.Add(1)
+		}
 		d, err := dp.factory(ctx)
 		if err == nil {
 			dp.drivers.Lock()
@@ -306,6 +345,9 @@ func (dp *DriverPool) spawnOne() {
 				return // done
 			}
 		}
+		if dp.metrics.spawn.err != nil {
+			dp.metrics.spawn.err.Add(1)
+		}
 		dp.Logger.Errorf("failed to start a driver: %v", err)
 		select {
 		case <-stop:
@@ -362,6 +404,10 @@ func (dp *DriverPool) setIdle(d Driver) {
 
 // killDriver stops are removes the driver from the queue.
 func (dp *DriverPool) killDriver(d Driver) {
+	if dp.metrics.spawn.kill != nil {
+		dp.metrics.spawn.kill.Add(1)
+	}
+
 	dp.drivers.Lock()
 	delete(dp.drivers.all, d)
 	delete(dp.drivers.idle, d)