Prometheus metrics (#590)

* prometheus additions to testmain (commented out right now)

* home of the npm prometheus metrics and tools for updating them, testing them

* add/remove policy metrics

* add/remove iptables rule metric measurements

* add/remove ipset metric measurements

* testing for gauges. want to soon remove the boolean for including prometheus in unit testing

* run http server that exposes prometheus from main

* cleaner test additions with less code

* removed incorrect instance of AddSet in the TestDeleteSet test

* added prometheus annotations to pod templates

* deleted unused file

* much more organized initialization of metrics now. now includes map from metric to metric name

* add ability to get summary count value. now getting gauge values and this new count value are done by passing the metric itself as a param instead of a string

* condenses prometheus testing code base by condensing all prometheus error messages into a function

* added testing for summary counts, condensed prometheus error handling code, and updated calls to use new form for getting metric values

* update based on variable spelling change in metrics package

* Added comments for functions and moved http handler code to the http file

* fixed problem of registering same metric name for different metrics, and passing in the wrong param type for testing

* made prometheus testing folder with interactive testing file. moved old random metric flux testing function over from ipsm_test

* moved testing around again

* fixed spelling mistake

* counting mistake in unit test

* handler variable ws in wrong file. Changed stdout printing to logging

* fixed parameter errors and counting error in a test

* moved utilities for testing prometheus metrics to npm/util. Updated StartHTTP to have an additional parameter for waiting after starting the server

* updated uses of StartHTTP to have the extra parameter

* updated GetValue and GetCountValue uses to use the prometheus features of the util package, which is now moved to a promutil package within npm/metrics/

* removed unnecessary comments, removed print statement, and added quantiles to all summary metrics

* fixed problem of double registering metrics

* wait longer for http server to start

* moved tool in test-util.go to promutil/util.go

* fixed timer to be in milliseconds and updated metric descriptions to mention units

* removed unnecessary comments

* http server always started in a go routine now. Added comment justifying the use of an http server

* debugging http connection refused in pipeline

* fixed syntax error

* removed debugging wrapper around http service

* sleep so that the testing metrics endpoint can be pinged

* redesigned GetValue and GetCountValue so that they don't use http calls

* removed random but helpful testing file - will write about quick testing in a wiki page

* milliseconds were being truncated. now they have decimals

* use direct Prometheus metric commands instead of wrapping them

* removed code used when testing was done through http server. Moved registering to metric creation functions

* added createGaugeVec, updated comments, made all help strings constants

* added metric that counts number of entries in each ipset. still need to add tests

* fixed creation of GaugeVecs, and use explicit labeling instead of order-based labeling now

* updated GetVecValue method signature

* added set to metrics on creation and wrote unit tests for CreateSet, AddToSet, DeleteFromSet, DeleteSet

* use custom registry to limit content that Container Insights scrapes. Also log the start of http server

* wrote TODO item comments for Restore and Destroy (currently these functions are only used in testing)

* NPM won't crash if a Prometheus metric fails to register now (unlikely). Added logging for metric registration/creation, and explicit public function to initialize metrics so that we can finish log config first

* initialize metrics in unit tests

* renamed util.go to test-util.go

Co-authored-by: Hunter Gregory <[email protected]>

Author: huntergregory

npm/azure-npm.yaml

@@ -49,7 +49,7 @@ roleRef:
   name: azure-npm
   apiGroup: rbac.authorization.k8s.io
 ---
-apiVersion: extensions/v1beta1
+apiVersion: apps/v1
 kind: DaemonSet
 metadata:
   name: azure-npm
@@ -67,6 +67,8 @@ spec:
         k8s-app: azure-npm
       annotations:
         scheduler.alpha.kubernetes.io/critical-pod: ''
+        prometheus.io/scrape: "true"
+        prometheus.io/port:   "8000"
     spec:
       priorityClassName: system-node-critical
       tolerations:

npm/ipsm/ipsm.go

@@ -9,7 +9,9 @@ import (
 	"syscall"
 
 	"github.com/Azure/azure-container-networking/log"
+	"github.com/Azure/azure-container-networking/npm/metrics"
 	"github.com/Azure/azure-container-networking/npm/util"
+	"github.com/prometheus/client_golang/prometheus"
 )
 
 type ipsEntry struct {
@@ -180,6 +182,8 @@ func (ipsMgr *IpsetManager) DeleteFromList(listName string, setName string) erro
 
 // CreateSet creates an ipset.
 func (ipsMgr *IpsetManager) CreateSet(setName string, spec []string) error {
+	timer := metrics.StartNewTimer()
+
 	if _, exists := ipsMgr.setMap[setName]; exists {
 		return nil
 	}
@@ -199,6 +203,10 @@ func (ipsMgr *IpsetManager) CreateSet(setName string, spec []string) error {
 
 	ipsMgr.setMap[setName] = NewIpset(setName)
 
+	metrics.NumIPSets.Inc()
+	timer.StopAndRecord(metrics.AddIPSetExecTime)
+	metrics.IPSetInventory.With(prometheus.Labels{metrics.SetNameLabel: setName}).Set(0)
+
 	return nil
 }
 
@@ -225,6 +233,9 @@ func (ipsMgr *IpsetManager) DeleteSet(setName string) error {
 
 	delete(ipsMgr.setMap, setName)
 
+	metrics.NumIPSets.Dec()
+	metrics.IPSetInventory.With(prometheus.Labels{metrics.SetNameLabel: setName}).Set(0)
+
 	return nil
 }
 
@@ -269,6 +280,8 @@ func (ipsMgr *IpsetManager) AddToSet(setName, ip, spec, podUid string) error {
 	// Stores the podUid as the context for this ip.
 	ipsMgr.setMap[setName].elements[ip] = podUid
 
+	metrics.IPSetInventory.With(prometheus.Labels{metrics.SetNameLabel: setName}).Inc()
+
 	return nil
 }
 
@@ -310,6 +323,8 @@ func (ipsMgr *IpsetManager) DeleteFromSet(setName, ip, podUid string) error {
 	// Now cleanup the cache
 	delete(ipsMgr.setMap[setName].elements, ip)
 
+	metrics.IPSetInventory.With(prometheus.Labels{metrics.SetNameLabel: setName}).Dec()
+
 	if len(ipsMgr.setMap[setName].elements) == 0 {
 		ipsMgr.DeleteSet(setName)
 	}
@@ -360,6 +375,8 @@ func (ipsMgr *IpsetManager) Destroy() error {
 		return err
 	}
 
+	//TODO set metrics.IPSetInventory to 0 for all set names
+
 	return nil
 }
 
@@ -424,5 +441,7 @@ func (ipsMgr *IpsetManager) Restore(configFile string) error {
 	}
 	cmd.Wait()
 
+	//TODO based on the set name and number of entries in the config file, update metrics.IPSetInventory
+
 	return nil
 }

npm/ipsm/ipsm_test.go

@@ -6,7 +6,10 @@ import (
 	"os"
 	"testing"
 
+	"github.com/Azure/azure-container-networking/npm/metrics"
+	"github.com/Azure/azure-container-networking/npm/metrics/promutil"
 	"github.com/Azure/azure-container-networking/npm/util"
+	"github.com/prometheus/client_golang/prometheus"
 )
 
 func TestSave(t *testing.T) {
@@ -127,14 +130,34 @@ func TestCreateSet(t *testing.T) {
 		}
 	}()
 
-	if err := ipsMgr.CreateSet("test-set", []string{util.IpsetNetHashFlag}); err != nil {
+	gaugeVal, err1 := promutil.GetValue(metrics.NumIPSets)
+	countVal, err2 := promutil.GetCountValue(metrics.AddIPSetExecTime)
+
+	testSet1Name := "test-set"
+	if err := ipsMgr.CreateSet(testSet1Name, []string{util.IpsetNetHashFlag}); err != nil {
 		t.Errorf("TestCreateSet failed @ ipsMgr.CreateSet")
 	}
 
+	testSet2Name := "test-set-with-maxelem"
 	spec := append([]string{util.IpsetNetHashFlag, util.IpsetMaxelemName, util.IpsetMaxelemNum})
-	if err := ipsMgr.CreateSet("test-set-with-maxelem", spec); err != nil {
+	if err := ipsMgr.CreateSet(testSet2Name, spec); err != nil {
 		t.Errorf("TestCreateSet failed @ ipsMgr.CreateSet when set maxelem")
 	}
+
+	newGaugeVal, err3 := promutil.GetValue(metrics.NumIPSets)
+	newCountVal, err4 := promutil.GetCountValue(metrics.AddIPSetExecTime)
+	testSet1Count, err5 := promutil.GetVecValue(metrics.IPSetInventory, prometheus.Labels{metrics.SetNameLabel: testSet1Name})
+	testSet2Count, err6 := promutil.GetVecValue(metrics.IPSetInventory, prometheus.Labels{metrics.SetNameLabel: testSet2Name})
+	promutil.NotifyIfErrors(t, err1, err2, err3, err4, err5, err6)
+	if newGaugeVal != gaugeVal+2 {
+		t.Errorf("Change in ipset number didn't register in Prometheus")
+	}
+	if newCountVal != countVal+2 {
+		t.Errorf("Execution time didn't register in Prometheus")
+	}
+	if testSet1Count != 0 || testSet2Count != 0 {
+		t.Errorf("Prometheus IPSet count has incorrect number of entries")
+	}
 }
 
 func TestDeleteSet(t *testing.T) {
@@ -149,13 +172,26 @@ func TestDeleteSet(t *testing.T) {
 		}
 	}()
 
-	if err := ipsMgr.CreateSet("test-set", append([]string{util.IpsetNetHashFlag})); err != nil {
+	testSetName := "test-set"
+	if err := ipsMgr.CreateSet(testSetName, append([]string{util.IpsetNetHashFlag})); err != nil {
 		t.Errorf("TestDeleteSet failed @ ipsMgr.CreateSet")
 	}
 
-	if err := ipsMgr.DeleteSet("test-set"); err != nil {
+	gaugeVal, err1 := promutil.GetValue(metrics.NumIPSets)
+
+	if err := ipsMgr.DeleteSet(testSetName); err != nil {
 		t.Errorf("TestDeleteSet failed @ ipsMgr.DeleteSet")
 	}
+
+	newGaugeVal, err2 := promutil.GetValue(metrics.NumIPSets)
+	testSetCount, err3 := promutil.GetVecValue(metrics.IPSetInventory, prometheus.Labels{metrics.SetNameLabel: testSetName})
+	promutil.NotifyIfErrors(t, err1, err2, err3)
+	if newGaugeVal != gaugeVal-1 {
+		t.Errorf("Change in ipset number didn't register in prometheus")
+	}
+	if testSetCount != 0 {
+		t.Errorf("Prometheus IPSet count has incorrect number of entries")
+	}
 }
 
 func TestAddToSet(t *testing.T) {
@@ -170,13 +206,20 @@ func TestAddToSet(t *testing.T) {
 		}
 	}()
 
-	if err := ipsMgr.AddToSet("test-set", "1.2.3.4", util.IpsetNetHashFlag, ""); err != nil {
+	testSetName := "test-set"
+	if err := ipsMgr.AddToSet(testSetName, "1.2.3.4", util.IpsetNetHashFlag, ""); err != nil {
 		t.Errorf("TestAddToSet failed @ ipsMgr.AddToSet")
 	}
 
-	if err := ipsMgr.AddToSet("test-set", "1.2.3.4/nomatch", util.IpsetNetHashFlag, ""); err != nil {
+	if err := ipsMgr.AddToSet(testSetName, "1.2.3.4/nomatch", util.IpsetNetHashFlag, ""); err != nil {
 		t.Errorf("TestAddToSet with nomatch failed @ ipsMgr.AddToSet")
 	}
+
+	testSetCount, err1 := promutil.GetVecValue(metrics.IPSetInventory, prometheus.Labels{metrics.SetNameLabel: testSetName})
+	promutil.NotifyIfErrors(t, err1)
+	if testSetCount != 2 {
+		t.Errorf("Prometheus IPSet count has incorrect number of entries")
+	}
 }
 
 func TestAddToSetWithCachePodInfo(t *testing.T) {
@@ -231,22 +274,29 @@ func TestDeleteFromSet(t *testing.T) {
 		}
 	}()
 
-	if err := ipsMgr.AddToSet("test-set", "1.2.3.4", util.IpsetNetHashFlag, ""); err != nil {
+	testSetName := "test-set"
+	if err := ipsMgr.AddToSet(testSetName, "1.2.3.4", util.IpsetNetHashFlag, ""); err != nil {
 		t.Errorf("TestDeleteFromSet failed @ ipsMgr.AddToSet")
 	}
 
-	if len(ipsMgr.setMap["test-set"].elements) != 1 {
+	if len(ipsMgr.setMap[testSetName].elements) != 1 {
 		t.Errorf("TestDeleteFromSet failed @ ipsMgr.AddToSet")
 	}
 
-	if err := ipsMgr.DeleteFromSet("test-set", "1.2.3.4", ""); err != nil {
+	if err := ipsMgr.DeleteFromSet(testSetName, "1.2.3.4", ""); err != nil {
 		t.Errorf("TestDeleteFromSet failed @ ipsMgr.DeleteFromSet")
 	}
 
 	// After deleting the only entry, "1.2.3.4" from "test-set", "test-set" ipset won't exist
-	if _, exists := ipsMgr.setMap["test-set"]; exists {
+	if _, exists := ipsMgr.setMap[testSetName]; exists {
 		t.Errorf("TestDeleteFromSet failed @ ipsMgr.DeleteFromSet")
 	}
+
+	testSetCount, err1 := promutil.GetVecValue(metrics.IPSetInventory, prometheus.Labels{metrics.SetNameLabel: testSetName})
+	promutil.NotifyIfErrors(t, err1)
+	if testSetCount != 0 {
+		t.Errorf("Prometheus IPSet count has incorrect number of entries")
+	}
 }
 
 func TestDeleteFromSetWithPodCache(t *testing.T) {
@@ -373,6 +423,7 @@ func TestRun(t *testing.T) {
 }
 
 func TestMain(m *testing.M) {
+	metrics.InitializeAll()
 	ipsMgr := NewIpsetManager()
 	ipsMgr.Save(util.IpsetConfigFile)
 

npm/iptm/iptm.go

@@ -17,6 +17,7 @@ import (
 	"golang.org/x/sys/unix"
 
 	"github.com/Azure/azure-container-networking/log"
+	"github.com/Azure/azure-container-networking/npm/metrics"
 	"github.com/Azure/azure-container-networking/npm/util"
 	"k8s.io/apimachinery/pkg/util/wait"
 	// utiliptables "k8s.io/kubernetes/pkg/util/iptables"
@@ -298,6 +299,8 @@ func (iptMgr *IptablesManager) DeleteChain(chain string) error {
 
 // Add adds a rule in iptables.
 func (iptMgr *IptablesManager) Add(entry *IptEntry) error {
+	timer := metrics.StartNewTimer()
+
 	log.Logf("Adding iptables entry: %+v.", entry)
 
 	if entry.IsJumpEntry {
@@ -310,6 +313,9 @@ func (iptMgr *IptablesManager) Add(entry *IptEntry) error {
 		return err
 	}
 
+	metrics.NumIPTableRules.Inc()
+	timer.StopAndRecord(metrics.AddIPTableRuleExecTime)
+
 	return nil
 }
 
@@ -332,6 +338,8 @@ func (iptMgr *IptablesManager) Delete(entry *IptEntry) error {
 		return err
 	}
 
+	metrics.NumIPTableRules.Dec()
+
 	return nil
 }
 

npm/iptm/iptm_test.go

@@ -1,9 +1,11 @@
 package iptm
 
 import (
-	"testing"
 	"os"
+	"testing"
 
+	"github.com/Azure/azure-container-networking/npm/metrics"
+	"github.com/Azure/azure-container-networking/npm/metrics/promutil"
 	"github.com/Azure/azure-container-networking/npm/util"
 )
 
@@ -147,9 +149,23 @@ func TestAdd(t *testing.T) {
 			util.IptablesReject,
 		},
 	}
+
+	gaugeVal, err1 := promutil.GetValue(metrics.NumIPTableRules)
+	countVal, err2 := promutil.GetCountValue(metrics.AddIPTableRuleExecTime)
+
 	if err := iptMgr.Add(entry); err != nil {
 		t.Errorf("TestAdd failed @ iptMgr.Add")
 	}
+
+	newGaugeVal, err3 := promutil.GetValue(metrics.NumIPTableRules)
+	newCountVal, err4 := promutil.GetCountValue(metrics.AddIPTableRuleExecTime)
+	promutil.NotifyIfErrors(t, err1, err2, err3, err4)
+	if newGaugeVal != gaugeVal+1 {
+		t.Errorf("Change in iptable rule number didn't register in prometheus")
+	}
+	if newCountVal != countVal+1 {
+		t.Errorf("Execution time didn't register in prometheus")
+	}
 }
 
 func TestDelete(t *testing.T) {
@@ -175,9 +191,17 @@ func TestDelete(t *testing.T) {
 		t.Errorf("TestDelete failed @ iptMgr.Add")
 	}
 
+	gaugeVal, err1 := promutil.GetValue(metrics.NumIPTableRules)
+
 	if err := iptMgr.Delete(entry); err != nil {
 		t.Errorf("TestDelete failed @ iptMgr.Delete")
 	}
+
+	newGaugeVal, err2 := promutil.GetValue(metrics.NumIPTableRules)
+	promutil.NotifyIfErrors(t, err1, err2)
+	if newGaugeVal != gaugeVal-1 {
+		t.Errorf("Change in iptable rule number didn't register in prometheus")
+	}
 }
 
 func TestRun(t *testing.T) {
@@ -202,6 +226,7 @@ func TestRun(t *testing.T) {
 }
 
 func TestMain(m *testing.M) {
+	metrics.InitializeAll()
 	iptMgr := NewIptablesManager()
 	iptMgr.Save(util.IptablesConfigFile)
 

npm/metrics/http.go

@@ -0,0 +1,43 @@
+package metrics
+
+import (
+	"net/http"
+	"time"
+
+	"github.com/Azure/azure-container-networking/log"
+	"github.com/prometheus/client_golang/prometheus/promhttp"
+)
+
+const (
+	// HTTPPort is the port used by the HTTP server (includes a preceding colon)
+	HTTPPort = ":8000"
+
+	//MetricsPath is the path for the Prometheus metrics endpoint (includes preceding slash)
+	MetricsPath = "/metrics"
+)
+
+var started = false
+var handler http.Handler
+
+// StartHTTP starts a HTTP server in a Go routine with endpoint on port 8000. Metrics are exposed on the endpoint /metrics.
+// By being exposed, the metrics can be scraped by a Prometheus Server or Container Insights.
+// The function will pause for delayAmountAfterStart seconds after starting the HTTP server for the first time.
+func StartHTTP(delayAmountAfterStart int) {
+	if started {
+		return
+	}
+	started = true
+
+	http.Handle(MetricsPath, getHandler())
+	log.Logf("Starting Prometheus HTTP Server")
+	go http.ListenAndServe(HTTPPort, nil)
+	time.Sleep(time.Second * time.Duration(delayAmountAfterStart))
+}
+
+// getHandler returns the HTTP handler for the metrics endpoint
+func getHandler() http.Handler {
+	if handler == nil {
+		handler = promhttp.HandlerFor(registry, promhttp.HandlerOpts{})
+	}
+	return handler
+}