Add metrics for "$upstream_connect_time" (#258)

* Add upstream_connect metrics

* Extract metrics stuff into own package

* Restructure remaining packages

features/response_times.feature

@@ -19,6 +19,17 @@ Feature: Upstream response times are summarized
       """
     Then the exporter should report value 20 for metric nginx_http_upstream_time_seconds{method="GET",status="200",quantile="0.5"}
 
+  Scenario: .5 quantile of upstream connect time is computed
+    Given a running exporter listening on "access.log" with upstream-connect-time format
+    When the following HTTP request is logged to "access.log"
+      """
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 10 5
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 20 5
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 30 10
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 40 10
+      """
+    Then the exporter should report value 5 for metric nginx_http_upstream_connect_time_seconds{method="GET",status="200",quantile="0.5"}
+
   Scenario: .5 quantile of response time is computed
     Given a running exporter listening on "access.log" with request-time format
     When the following HTTP request is logged to "access.log"

features/steps/steps.py

@@ -8,6 +8,7 @@
 formats = {
     "default": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for"',
     "upstream-time": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $upstream_response_time',
+    "upstream-connect-time": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $upstream_response_time $upstream_connect_time',
     "request-time": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $request_time'
 }
 

main.go

@@ -27,148 +27,19 @@ import (
 	"sync"
 	"syscall"
 
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/syslog"
-
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/config"
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/discovery"
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/parser"
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/prof"
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/relabeling"
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/tail"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/config"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/discovery"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/metrics"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/parser"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/prof"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/relabeling"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/syslog"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/tail"
+
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
 )
 
-type NSMetrics struct {
-	cfg      *config.NamespaceConfig
-	registry *prometheus.Registry
-	Metrics
-}
-
-func NewNSMetrics(cfg *config.NamespaceConfig) *NSMetrics {
-	m := &NSMetrics{
-		cfg:      cfg,
-		registry: prometheus.NewRegistry(),
-	}
-	m.Init(cfg)
-
-	m.registry.MustRegister(m.countTotal)
-	m.registry.MustRegister(m.requestBytesTotal)
-	m.registry.MustRegister(m.responseBytesTotal)
-	m.registry.MustRegister(m.upstreamSeconds)
-	m.registry.MustRegister(m.upstreamSecondsHist)
-	m.registry.MustRegister(m.responseSeconds)
-	m.registry.MustRegister(m.responseSecondsHist)
-	m.registry.MustRegister(m.parseErrorsTotal)
-	return m
-}
-
-// Metrics is a struct containing pointers to all metrics that should be
-// exposed to Prometheus
-type Metrics struct {
-	countTotal          *prometheus.CounterVec
-	responseBytesTotal  *prometheus.CounterVec
-	requestBytesTotal   *prometheus.CounterVec
-	upstreamSeconds     *prometheus.SummaryVec
-	upstreamSecondsHist *prometheus.HistogramVec
-	responseSeconds     *prometheus.SummaryVec
-	responseSecondsHist *prometheus.HistogramVec
-	parseErrorsTotal    prometheus.Counter
-}
-
-func inLabels(label string, labels []string) bool {
-	for _, l := range labels {
-		if label == l {
-			return true
-		}
-	}
-	return false
-}
-
-// Init initializes a metrics struct
-func (m *Metrics) Init(cfg *config.NamespaceConfig) {
-	cfg.MustCompile()
-
-	labels := cfg.OrderedLabelNames
-	counterLabels := labels
-
-	for i := range cfg.RelabelConfigs {
-		if !cfg.RelabelConfigs[i].OnlyCounter {
-			labels = append(labels, cfg.RelabelConfigs[i].TargetLabel)
-		}
-		counterLabels = append(counterLabels, cfg.RelabelConfigs[i].TargetLabel)
-	}
-
-	for _, r := range relabeling.DefaultRelabelings {
-		if !inLabels(r.TargetLabel, labels) {
-			labels = append(labels, r.TargetLabel)
-		}
-		if !inLabels(r.TargetLabel, counterLabels) {
-			counterLabels = append(counterLabels, r.TargetLabel)
-		}
-	}
-
-	m.countTotal = prometheus.NewCounterVec(prometheus.CounterOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_response_count_total",
-		Help:        "Amount of processed HTTP requests",
-	}, counterLabels)
-
-	m.responseBytesTotal = prometheus.NewCounterVec(prometheus.CounterOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_response_size_bytes",
-		Help:        "Total amount of transferred bytes",
-	}, labels)
-
-	m.requestBytesTotal = prometheus.NewCounterVec(prometheus.CounterOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_request_size_bytes",
-		Help:        "Total amount of received bytes",
-	}, labels)
-
-	m.upstreamSeconds = prometheus.NewSummaryVec(prometheus.SummaryOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_upstream_time_seconds",
-		Help:        "Time needed by upstream servers to handle requests",
-		Objectives:  map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
-	}, labels)
-
-	m.upstreamSecondsHist = prometheus.NewHistogramVec(prometheus.HistogramOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_upstream_time_seconds_hist",
-		Help:        "Time needed by upstream servers to handle requests",
-		Buckets:     cfg.HistogramBuckets,
-	}, labels)
-
-	m.responseSeconds = prometheus.NewSummaryVec(prometheus.SummaryOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_response_time_seconds",
-		Help:        "Time needed by NGINX to handle requests",
-		Objectives:  map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
-	}, labels)
-
-	m.responseSecondsHist = prometheus.NewHistogramVec(prometheus.HistogramOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "http_response_time_seconds_hist",
-		Help:        "Time needed by NGINX to handle requests",
-		Buckets:     cfg.HistogramBuckets,
-	}, labels)
-
-	m.parseErrorsTotal = prometheus.NewCounter(prometheus.CounterOpts{
-		Namespace:   cfg.NamespacePrefix,
-		ConstLabels: cfg.NamespaceLabels,
-		Name:        "parse_errors_total",
-		Help:        "Total number of log file lines that could not be parsed",
-	})
-}
-
 func main() {
 	var opts config.StartupFlags
 	var cfg = config.Config{
@@ -237,11 +108,11 @@ func main() {
 	}
 
 	for _, ns := range cfg.Namespaces {
-		nsMetrics := NewNSMetrics(&ns)
-		nsGatherers = append(nsGatherers, nsMetrics.registry)
+		nsMetrics := metrics.NewForNamespace(&ns)
+		nsGatherers = append(nsGatherers, nsMetrics.Gatherer())
 
 		fmt.Printf("starting listener for namespace %s\n", ns.Name)
-		go processNamespace(ns, &(nsMetrics.Metrics))
+		go processNamespace(ns, &(nsMetrics.Collection))
 	}
 
 	listenAddr := fmt.Sprintf("%s:%d", cfg.Listen.Address, cfg.Listen.Port)
@@ -300,7 +171,7 @@ func setupConsul(cfg *config.Config, stopChan <-chan bool, stopHandlers *sync.Wa
 	stopHandlers.Add(1)
 }
 
-func processNamespace(nsCfg config.NamespaceConfig, metrics *Metrics) {
+func processNamespace(nsCfg config.NamespaceConfig, metrics *metrics.Collection) {
 	var followers []tail.Follower
 
 	parser := parser.NewParser(nsCfg)
@@ -356,7 +227,7 @@ func processNamespace(nsCfg config.NamespaceConfig, metrics *Metrics) {
 
 }
 
-func processSource(nsCfg config.NamespaceConfig, t tail.Follower, parser parser.Parser, metrics *Metrics, hasCounterOnlyLabels bool) {
+func processSource(nsCfg config.NamespaceConfig, t tail.Follower, parser parser.Parser, metrics *metrics.Collection, hasCounterOnlyLabels bool) {
 	relabelings := relabeling.NewRelabelings(nsCfg.RelabelConfigs)
 	relabelings = append(relabelings, relabeling.DefaultRelabelings...)
 	relabelings = relabeling.UniqueRelabelings(relabelings)
@@ -377,7 +248,7 @@ func processSource(nsCfg config.NamespaceConfig, t tail.Follower, parser parser.
 		fields, err := parser.ParseString(line)
 		if err != nil {
 			fmt.Printf("error while parsing line '%s': %s\n", line, err)
-			metrics.parseErrorsTotal.Inc()
+			metrics.ParseErrorsTotal.Inc()
 			continue
 		}
 
@@ -397,24 +268,29 @@ func processSource(nsCfg config.NamespaceConfig, t tail.Follower, parser parser.
 			notCounterValues = labelValues
 		}
 
-		metrics.countTotal.WithLabelValues(labelValues...).Inc()
+		metrics.CountTotal.WithLabelValues(labelValues...).Inc()
+
+		if v, ok := observeMetrics(fields, "body_bytes_sent", floatFromFields, metrics.ParseErrorsTotal); ok {
+			metrics.ResponseBytesTotal.WithLabelValues(notCounterValues...).Add(v)
+		}
 
-		if v, ok := observeMetrics(fields, "body_bytes_sent", floatFromFields, metrics.parseErrorsTotal); ok {
-			metrics.responseBytesTotal.WithLabelValues(notCounterValues...).Add(v)
+		if v, ok := observeMetrics(fields, "request_length", floatFromFields, metrics.ParseErrorsTotal); ok {
+			metrics.RequestBytesTotal.WithLabelValues(notCounterValues...).Add(v)
 		}
 
-		if v, ok := observeMetrics(fields, "request_length", floatFromFields, metrics.parseErrorsTotal); ok {
-			metrics.requestBytesTotal.WithLabelValues(notCounterValues...).Add(v)
+		if v, ok := observeMetrics(fields, "upstream_response_time", floatFromFieldsMulti, metrics.ParseErrorsTotal); ok {
+			metrics.UpstreamSeconds.WithLabelValues(notCounterValues...).Observe(v)
+			metrics.UpstreamSecondsHist.WithLabelValues(notCounterValues...).Observe(v)
 		}
 
-		if v, ok := observeMetrics(fields, "upstream_response_time", floatFromFieldsMulti, metrics.parseErrorsTotal); ok {
-			metrics.upstreamSeconds.WithLabelValues(notCounterValues...).Observe(v)
-			metrics.upstreamSecondsHist.WithLabelValues(notCounterValues...).Observe(v)
+		if v, ok := observeMetrics(fields, "upstream_connect_time", floatFromFieldsMulti, metrics.ParseErrorsTotal); ok {
+			metrics.UpstreamConnectSeconds.WithLabelValues(notCounterValues...).Observe(v)
+			metrics.UpstreamConnectSecondsHist.WithLabelValues(notCounterValues...).Observe(v)
 		}
 
-		if v, ok := observeMetrics(fields, "request_time", floatFromFields, metrics.parseErrorsTotal); ok {
-			metrics.responseSeconds.WithLabelValues(notCounterValues...).Observe(v)
-			metrics.responseSecondsHist.WithLabelValues(notCounterValues...).Observe(v)
+		if v, ok := observeMetrics(fields, "request_time", floatFromFields, metrics.ParseErrorsTotal); ok {
+			metrics.ResponseSeconds.WithLabelValues(notCounterValues...).Observe(v)
+			metrics.ResponseSecondsHist.WithLabelValues(notCounterValues...).Observe(v)
 		}
 	}
 }

config/loader_hcl.go → pkg/config/loader_hcl.go

@@ -1,9 +1,10 @@
 package config
 
 import (
-	"github.com/hashicorp/hcl"
 	"io"
 	"io/ioutil"
+
+	"github.com/hashicorp/hcl"
 )
 
 func loadConfigFromHCLStream(config *Config, file io.Reader) error {

config/loader_yaml.go → pkg/config/loader_yaml.go

@@ -1,9 +1,10 @@
 package config
 
 import (
-	"gopkg.in/yaml.v2"
 	"io"
 	"io/ioutil"
+
+	"gopkg.in/yaml.v2"
 )
 
 func loadConfigFromYAMLStream(config *Config, file io.Reader) error {

discovery/consul.go → pkg/discovery/consul.go

@@ -2,7 +2,7 @@ package discovery
 
 import (
 	"github.com/hashicorp/consul/api"
-	"github.com/martin-helmich/prometheus-nginxlog-exporter/config"
+	"github.com/martin-helmich/prometheus-nginxlog-exporter/pkg/config"
 )
 
 // ConsulRegistrator is a helper struct that handles Consul service registration

pkg/metrics/collection.go

@@ -0,0 +1,18 @@
+package metrics
+
+import "github.com/prometheus/client_golang/prometheus"
+
+// Collection is a struct containing pointers to all metrics that should be
+// exposed to Prometheus
+type Collection struct {
+	CountTotal                 *prometheus.CounterVec
+	ResponseBytesTotal         *prometheus.CounterVec
+	RequestBytesTotal          *prometheus.CounterVec
+	UpstreamSeconds            *prometheus.SummaryVec
+	UpstreamSecondsHist        *prometheus.HistogramVec
+	UpstreamConnectSeconds     *prometheus.SummaryVec
+	UpstreamConnectSecondsHist *prometheus.HistogramVec
+	ResponseSeconds            *prometheus.SummaryVec
+	ResponseSecondsHist        *prometheus.HistogramVec
+	ParseErrorsTotal           prometheus.Counter
+}