Token creation counters (#9052)

* Add token creation counters.
* Created a utility to change TTL to bucket name.
* Add counter covering token creation for response wrapping.
* Fix namespace label, with a new utility function.

helper/metricsutil/bucket.go

@@ -0,0 +1,39 @@
+package metricsutil
+
+import (
+	"sort"
+	"time"
+)
+
+var bucketBoundaries = []struct {
+	Value time.Duration
+	Label string
+}{
+	{1 * time.Minute, "1m"},
+	{10 * time.Minute, "10m"},
+	{20 * time.Minute, "20m"},
+	{1 * time.Hour, "1h"},
+	{2 * time.Hour, "2h"},
+	{24 * time.Hour, "1d"},
+	{2 * 24 * time.Hour, "2d"},
+	{7 * 24 * time.Hour, "7d"},
+	{30 * 24 * time.Hour, "30d"},
+}
+
+const overflowBucket = "+Inf"
+
+// TTLBucket computes the label to apply for a token TTL.
+func TTLBucket(ttl time.Duration) string {
+	upperBound := sort.Search(
+		len(bucketBoundaries),
+		func(i int) bool {
+			return ttl <= bucketBoundaries[i].Value
+		},
+	)
+	if upperBound >= len(bucketBoundaries) {
+		return overflowBucket
+	} else {
+		return bucketBoundaries[upperBound].Label
+	}
+
+}

helper/metricsutil/bucket_test.go

@@ -0,0 +1,28 @@
+package metricsutil
+
+import (
+	"testing"
+	"time"
+)
+
+func TestTTLBucket_Lookup(t *testing.T) {
+	testCases := []struct {
+		Input    time.Duration
+		Expected string
+	}{
+		{30 * time.Second, "1m"},
+		{0 * time.Second, "1m"},
+		{2 * time.Hour, "2h"},
+		{2*time.Hour - time.Second, "2h"},
+		{2*time.Hour + time.Second, "1d"},
+		{30 * 24 * time.Hour, "30d"},
+		{31 * 24 * time.Hour, "+Inf"},
+	}
+
+	for _, tc := range testCases {
+		bucket := TTLBucket(tc.Input)
+		if bucket != tc.Expected {
+			t.Errorf("Expected %q, got %q for duration %v.", tc.Expected, bucket, tc.Input)
+		}
+	}
+}

helper/metricsutil/wrapped_metrics.go

@@ -1,9 +1,11 @@
 package metricsutil
 
 import (
+	"strings"
 	"time"
 
 	metrics "github.com/armon/go-metrics"
+	"github.com/hashicorp/vault/helper/namespace"
 )
 
 // ClusterMetricSink serves as a shim around go-metrics
@@ -68,3 +70,18 @@ func (m *ClusterMetricSink) SetDefaultClusterName(clusterName string) {
 		m.ClusterName = clusterName
 	}
 }
+
+// NamespaceLabel creates a metrics label for the given
+// Namespace: root is "root"; others are path with the
+// final '/' removed.
+func NamespaceLabel(ns *namespace.Namespace) metrics.Label {
+	switch {
+	case ns == nil:
+		return metrics.Label{"namespace", "root"}
+	case ns.ID == namespace.RootNamespaceID:
+		return metrics.Label{"namespace", "root"}
+	default:
+		return metrics.Label{"namespace",
+			strings.Trim(ns.Path, "/")}
+	}
+}

vault/request_handling.go

@@ -13,6 +13,7 @@ import (
 	multierror "github.com/hashicorp/go-multierror"
 	sockaddr "github.com/hashicorp/go-sockaddr"
 	"github.com/hashicorp/vault/helper/identity"
+	"github.com/hashicorp/vault/helper/metricsutil"
 	"github.com/hashicorp/vault/helper/namespace"
 	"github.com/hashicorp/vault/internalshared/configutil"
 	"github.com/hashicorp/vault/sdk/framework"
@@ -1181,6 +1182,19 @@ func (c *Core) handleLoginRequest(ctx context.Context, req *logical.Request) (re
 		// Attach the display name, might be used by audit backends
 		req.DisplayName = auth.DisplayName
 
+		// Count the successful token creation
+		ttl_label := metricsutil.TTLBucket(tokenTTL)
+		c.metricSink.IncrCounterWithLabels(
+			[]string{"token", "creation"},
+			1,
+			[]metrics.Label{
+				metricsutil.NamespaceLabel(ns),
+				{"auth_method", req.MountType},
+				{"mount_point", req.MountPoint},
+				{"creation_ttl", ttl_label},
+				{"token_type", auth.TokenType.String()},
+			},
+		)
 	}
 
 	return resp, auth, routeErr

vault/request_handling_test.go

@@ -1,11 +1,14 @@
 package vault
 
 import (
+	"strings"
 	"testing"
 	"time"
 
+	"github.com/armon/go-metrics"
 	uuid "github.com/hashicorp/go-uuid"
 	credUserpass "github.com/hashicorp/vault/builtin/credential/userpass"
+	"github.com/hashicorp/vault/helper/metricsutil"
 	"github.com/hashicorp/vault/helper/namespace"
 	"github.com/hashicorp/vault/sdk/logical"
 )
@@ -144,3 +147,153 @@ func TestRequestHandling_LoginWrapping(t *testing.T) {
 		t.Fatalf("bad: %#v", resp)
 	}
 }
+
+func labelsMatch(actual, expected map[string]string) bool {
+	for expected_label, expected_val := range expected {
+		if v, ok := actual[expected_label]; ok {
+			if v != expected_val {
+				return false
+			}
+		} else {
+			return false
+		}
+	}
+	return true
+}
+
+func checkCounter(t *testing.T, inmemSink *metrics.InmemSink, keyPrefix string, expectedLabels map[string]string) {
+	t.Helper()
+
+	intervals := inmemSink.Data()
+	if len(intervals) > 1 {
+		t.Skip("Detected interval crossing.")
+	}
+
+	var counter *metrics.SampledValue = nil
+	var labels map[string]string
+	for _, c := range intervals[0].Counters {
+		if !strings.HasPrefix(c.Name, keyPrefix) {
+			continue
+		}
+		counter = &c
+
+		labels = make(map[string]string)
+		for _, l := range counter.Labels {
+			labels[l.Name] = l.Value
+		}
+
+		// Distinguish between different label sets
+		if labelsMatch(labels, expectedLabels) {
+			break
+		}
+	}
+	if counter == nil {
+		t.Fatalf("No %q counter found with matching labels", keyPrefix)
+	}
+
+	if !labelsMatch(labels, expectedLabels) {
+		t.Errorf("No matching label set, found %v", labels)
+	}
+
+	if counter.Count != 1 {
+		t.Errorf("Counter number of samples %v is not 1.", counter.Count)
+	}
+
+	if counter.Sum != 1.0 {
+		t.Errorf("Counter sum %v is not 1.", counter.Sum)
+	}
+
+}
+
+func TestRequestHandling_LoginMetric(t *testing.T) {
+	core, _, root := TestCoreUnsealed(t)
+
+	if err := core.loadMounts(namespace.RootContext(nil)); err != nil {
+		t.Fatalf("err: %v", err)
+	}
+
+	core.credentialBackends["userpass"] = credUserpass.Factory
+
+	inmemSink := metrics.NewInmemSink(
+		1000000*time.Hour,
+		2000000*time.Hour)
+	core.metricSink = &metricsutil.ClusterMetricSink{
+		ClusterName: "test-cluster",
+		Sink:        inmemSink,
+	}
+
+	// Setup mount
+	req := &logical.Request{
+		Path:        "sys/auth/userpass",
+		ClientToken: root,
+		Operation:   logical.UpdateOperation,
+		Data: map[string]interface{}{
+			"type": "userpass",
+		},
+		Connection: &logical.Connection{},
+	}
+	resp, err := core.HandleRequest(namespace.RootContext(nil), req)
+	if err != nil {
+		t.Fatalf("err: %v", err)
+	}
+	if resp != nil {
+		t.Fatalf("bad: %#v", resp)
+	}
+
+	// Create user
+	req.Path = "auth/userpass/users/test"
+	req.Data = map[string]interface{}{
+		"password": "foo",
+		"policies": "default",
+	}
+	resp, err = core.HandleRequest(namespace.RootContext(nil), req)
+	if err != nil {
+		t.Fatalf("err: %v", err)
+	}
+	if resp != nil {
+		t.Fatalf("bad: %#v", resp)
+	}
+
+	// Login with response wrapping
+	req = &logical.Request{
+		Path:      "auth/userpass/login/test",
+		Operation: logical.UpdateOperation,
+		Data: map[string]interface{}{
+			"password": "foo",
+		},
+		WrapInfo: &logical.RequestWrapInfo{
+			TTL: time.Duration(15 * time.Second),
+		},
+		Connection: &logical.Connection{},
+	}
+	resp, err = core.HandleRequest(namespace.RootContext(nil), req)
+	if err != nil {
+		t.Fatalf("err: %v", err)
+	}
+	if resp == nil {
+		t.Fatalf("bad: %v", resp)
+	}
+
+	// There should be two counters
+	checkCounter(t, inmemSink, "token.creation",
+		map[string]string{
+			"cluster":      "test-cluster",
+			"namespace":    "root",
+			"auth_method":  "userpass",
+			"mount_point":  "auth/userpass/",
+			"creation_ttl": "+Inf",
+			"token_type":   "service",
+		},
+	)
+	checkCounter(t, inmemSink, "token.creation",
+		map[string]string{
+			"cluster":      "test-cluster",
+			"namespace":    "root",
+			"auth_method":  "response_wrapping",
+			"mount_point":  "auth/userpass/",
+			"creation_ttl": "1m",
+			"token_type":   "service",
+		},
+	)
+
+}

vault/token_store.go

@@ -20,6 +20,7 @@ import (
 	"github.com/hashicorp/go-multierror"
 	"github.com/hashicorp/go-sockaddr"
 	"github.com/hashicorp/vault/helper/identity"
+	"github.com/hashicorp/vault/helper/metricsutil"
 	"github.com/hashicorp/vault/helper/namespace"
 	"github.com/hashicorp/vault/sdk/framework"
 	"github.com/hashicorp/vault/sdk/helper/base62"
@@ -2716,6 +2717,20 @@ func (ts *TokenStore) handleCreateCommon(ctx context.Context, req *logical.Reque
 		return logical.ErrorResponse(err.Error()), logical.ErrInvalidRequest
 	}
 
+	// Count the successful token creation.
+	ttl_label := metricsutil.TTLBucket(te.TTL)
+	ts.core.metricSink.IncrCounterWithLabels(
+		[]string{"token", "creation"},
+		1,
+		[]metrics.Label{
+			metricsutil.NamespaceLabel(ns),
+			{"auth_method", "token"},
+			{"mount_point", req.MountPoint}, // path, not accessor
+			{"creation_ttl", ttl_label},
+			{"token_type", tokenType.String()},
+		},
+	)
+
 	// Generate the response
 	resp.Auth = &logical.Auth{
 		NumUses:     te.NumUses,

vault/token_store_test.go

@@ -13,12 +13,14 @@ import (
 	"testing"
 	"time"
 
+	"github.com/armon/go-metrics"
 	"github.com/go-test/deep"
 	"github.com/hashicorp/errwrap"
 	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/go-sockaddr"
 	"github.com/hashicorp/go-uuid"
 	"github.com/hashicorp/vault/helper/identity"
+	"github.com/hashicorp/vault/helper/metricsutil"
 	"github.com/hashicorp/vault/helper/namespace"
 	"github.com/hashicorp/vault/sdk/helper/locksutil"
 	"github.com/hashicorp/vault/sdk/helper/parseutil"
@@ -2119,6 +2121,79 @@ func TestTokenStore_HandleRequest_CreateToken_TTL(t *testing.T) {
 	}
 }
 
+func TestTokenStore_HandleRequest_CreateToken_Metric(t *testing.T) {
+	c, _, root := TestCoreUnsealed(t)
+	ts := c.tokenStore
+
+	inmemSink := metrics.NewInmemSink(
+		1000000*time.Hour,
+		2000000*time.Hour)
+	c.metricSink = &metricsutil.ClusterMetricSink{
+		ClusterName: "test-cluster",
+		Sink:        inmemSink,
+	}
+
+	req := logical.TestRequest(t, logical.UpdateOperation, "create")
+	req.ClientToken = root
+	req.Data["ttl"] = "3h"
+	req.Data["policies"] = []string{"foo"}
+	req.MountPoint = "test/mount"
+
+	resp := testMakeTokenViaRequest(t, ts, req)
+	if resp.Auth.ClientToken == "" {
+		t.Fatalf("bad: %#v", resp)
+	}
+
+	intervals := inmemSink.Data()
+	// Test crossed an interval boundary, don't try to deal with it.
+	if len(intervals) > 1 {
+		t.Skip("Detected interval crossing.")
+	}
+
+	keyPrefix := "token.creation"
+	var counter *metrics.SampledValue = nil
+
+	for _, c := range intervals[0].Counters {
+		if strings.HasPrefix(c.Name, keyPrefix) {
+			counter = &c
+			break
+		}
+	}
+	if counter == nil {
+		t.Fatal("No token.creation counter found.")
+	}
+
+	if counter.Count != 1 {
+		t.Errorf("Counter number of samples %v is not 1.", counter.Count)
+	}
+
+	if counter.Sum != 1.0 {
+		t.Errorf("Counter sum %v is not 1.", counter.Sum)
+	}
+
+	labels := make(map[string]string)
+	for _, l := range counter.Labels {
+		labels[l.Name] = l.Value
+	}
+	expected := map[string]string{
+		"cluster":      "test-cluster",
+		"namespace":    "root",
+		"auth_method":  "token",
+		"mount_point":  req.MountPoint,
+		"creation_ttl": "1d",
+		"token_type":   "service",
+	}
+	for expected_label, expected_val := range expected {
+		if v, ok := labels[expected_label]; ok {
+			if v != expected_val {
+				t.Errorf("Label %q incorrect, expected %q, got %q", expected_label, expected_val, v)
+			}
+		} else {
+			t.Errorf("Label %q missing", expected_label)
+		}
+	}
+}
+
 func TestTokenStore_HandleRequest_Revoke(t *testing.T) {
 	exp := mockExpiration(t)
 	ts := exp.tokenStore

vault/wrapping.go

@@ -10,7 +10,9 @@ import (
 	"strings"
 	"time"
 
+	"github.com/armon/go-metrics"
 	"github.com/hashicorp/errwrap"
+	"github.com/hashicorp/vault/helper/metricsutil"
 	"github.com/hashicorp/vault/helper/namespace"
 	"github.com/hashicorp/vault/sdk/helper/certutil"
 	"github.com/hashicorp/vault/sdk/helper/consts"
@@ -143,6 +145,24 @@ DONELISTHANDLING:
 		return nil, ErrInternalError
 	}
 
+	// Count the successful token creation
+	ttl_label := metricsutil.TTLBucket(resp.WrapInfo.TTL)
+	c.metricSink.IncrCounterWithLabels(
+		[]string{"token", "creation"},
+		1,
+		[]metrics.Label{
+			metricsutil.NamespaceLabel(ns),
+			// The type of the secret engine is not all that useful;
+			// we could use "token" but let's be more descriptive,
+			// even if it's not a real auth method.
+			{"auth_method", "response_wrapping"},
+			{"mount_point", req.MountPoint},
+			{"creation_ttl", ttl_label},
+			// *Should* be service, but let's use whatever create() did..
+			{"token_type", te.Type.String()},
+		},
+	)
+
 	resp.WrapInfo.Token = te.ID
 	resp.WrapInfo.Accessor = te.Accessor
 	resp.WrapInfo.CreationTime = creationTime