metrics: make metrics easier to use with prometheus (#4020)

* make TagCounter metrics easier to use with prometheus

* ensure 0 counters are logged

* allow for pre-declaring TagCounter tags for use with prometheus

* fix expected in TestTagCounterWriteMetric

* deregister counter used in test

* fix lint warning

* CR comment

* Log incorrect metrics for debugging test failures

* deregister more counters and tagcounters used by tests

* remove unused Segment

Author: cce

agreement/gossip/network.go

@@ -32,9 +32,11 @@ import (
 )
 
 var messagesHandledTotal = metrics.MakeCounter(metrics.AgreementMessagesHandled)
-var messagesHandledByType = metrics.NewTagCounter("algod_agreement_handled_{TAG}", "Number of agreement messages handled per type")
+var messagesHandledByType = metrics.NewTagCounter("algod_agreement_handled_{TAG}", "Number of agreement {TAG} messages handled",
+	agreementVoteMessageType, agreementProposalMessageType, agreementBundleMessageType)
 var messagesDroppedTotal = metrics.MakeCounter(metrics.AgreementMessagesDropped)
-var messagesDroppedByType = metrics.NewTagCounter("algod_agreement_dropped_{TAG}", "Number of agreement messages handled per type")
+var messagesDroppedByType = metrics.NewTagCounter("algod_agreement_dropped_{TAG}", "Number of agreement {TAG} messages dropped",
+	agreementVoteMessageType, agreementProposalMessageType, agreementBundleMessageType)
 
 const (
 	agreementVoteMessageType     = "vote"

agreement/pseudonode.go

@@ -44,8 +44,8 @@ var errPseudonodeVerifierClosedChannel = errors.New("crypto verifier closed the
 var errPseudonodeNoVotes = errors.New("no valid participation keys to generate votes for given round")
 var errPseudonodeNoProposals = errors.New("no valid participation keys to generate proposals for given round")
 
-var pseudonodeBacklogFullByType = metrics.NewTagCounter("algod_agreement_pseudonode_tasks_dropped_{TAG}", "Number of pseudonode tasks dropped per type")
-var pseudonodeResultTimeoutsByType = metrics.NewTagCounter("algod_agreement_pseudonode_tasks_timeouts_{TAG}", "Number of pseudonode task result timeouts per type")
+var pseudonodeBacklogFullByType = metrics.NewTagCounter("algod_agreement_pseudonode_tasks_dropped_{TAG}", "Number of pseudonode {TAG} tasks dropped", "proposal", "vote")
+var pseudonodeResultTimeoutsByType = metrics.NewTagCounter("algod_agreement_pseudonode_tasks_timeouts_{TAG}", "Number of pseudonode {TAG} task result timeouts", "vote", "pvote", "ppayload")
 
 // A pseudonode creates proposals and votes with a KeyManager which holds participation keys.
 //

network/wsPeer.go

@@ -48,14 +48,14 @@ const averageMessageLength = 2 * 1024    // Most of the messages are smaller tha
 const msgsInReadBufferPerPeer = 10
 
 var networkSentBytesTotal = metrics.MakeCounter(metrics.NetworkSentBytesTotal)
-var networkSentBytesByTag = metrics.NewTagCounter("algod_network_sent_bytes_{TAG}", "Number of bytes that were sent over the network per message tag")
+var networkSentBytesByTag = metrics.NewTagCounter("algod_network_sent_bytes_{TAG}", "Number of bytes that were sent over the network for {TAG} messages")
 var networkReceivedBytesTotal = metrics.MakeCounter(metrics.NetworkReceivedBytesTotal)
-var networkReceivedBytesByTag = metrics.NewTagCounter("algod_network_received_bytes_{TAG}", "Number of bytes that were received from the network per message tag")
+var networkReceivedBytesByTag = metrics.NewTagCounter("algod_network_received_bytes_{TAG}", "Number of bytes that were received from the network for {TAG} messages")
 
 var networkMessageReceivedTotal = metrics.MakeCounter(metrics.NetworkMessageReceivedTotal)
-var networkMessageReceivedByTag = metrics.NewTagCounter("algod_network_message_received_{TAG}", "Number of complete messages that were received from the network per message tag")
+var networkMessageReceivedByTag = metrics.NewTagCounter("algod_network_message_received_{TAG}", "Number of complete messages that were received from the network for {TAG} messages")
 var networkMessageSentTotal = metrics.MakeCounter(metrics.NetworkMessageSentTotal)
-var networkMessageSentByTag = metrics.NewTagCounter("algod_network_message_sent_{TAG}", "Number of complete messages that were sent to the network per message tag")
+var networkMessageSentByTag = metrics.NewTagCounter("algod_network_message_sent_{TAG}", "Number of complete messages that were sent to the network for {TAG} messages")
 
 var networkConnectionsDroppedTotal = metrics.MakeCounter(metrics.NetworkConnectionsDroppedTotal)
 var networkMessageQueueMicrosTotal = metrics.MakeCounter(metrics.MetricName{Name: "algod_network_message_sent_queue_micros_total", Description: "Total microseconds message spent waiting in queue to be sent"})

util/metrics/counter.go

@@ -155,16 +155,24 @@ func (counter *Counter) WriteMetric(buf *strings.Builder, parentLabels string) {
 	counter.Lock()
 	defer counter.Unlock()
 
-	if len(counter.values) < 1 {
-		return
-	}
 	buf.WriteString("# HELP ")
 	buf.WriteString(counter.name)
 	buf.WriteString(" ")
 	buf.WriteString(counter.description)
 	buf.WriteString("\n# TYPE ")
 	buf.WriteString(counter.name)
 	buf.WriteString(" counter\n")
+	// if counter is zero, report 0 using parentLabels and no tags
+	if len(counter.values) == 0 {
+		buf.WriteString(counter.name)
+		if len(parentLabels) > 0 {
+			buf.WriteString("{" + parentLabels + "}")
+		}
+		buf.WriteString(" 0")
+		buf.WriteString("\n")
+		return
+	}
+	// otherwise iterate through values and write one line per label
 	for _, l := range counter.values {
 		buf.WriteString(counter.name)
 		buf.WriteString("{")

util/metrics/counter_test.go

@@ -19,6 +19,7 @@ package metrics
 import (
 	"context"
 	"fmt"
+	"strings"
 	"testing"
 	"time"
 
@@ -67,7 +68,7 @@ func TestMetricCounter(t *testing.T) {
 	defer test.Unlock()
 	// the the loop above we've created a single metric name with five different labels set ( host0, host1 .. host 4)
 	// let's see if we received all the 5 different labels.
-	require.Equal(t, 5, len(test.metrics), "Missing metric counts were reported.")
+	require.Equal(t, 5, len(test.metrics), "Missing metric counts were reported: %+v", test.metrics)
 
 	for k, v := range test.metrics {
 		// we have increased each one of the labels exactly 4 times. See that the counter was counting correctly.
@@ -114,7 +115,7 @@ func TestMetricCounterFastInts(t *testing.T) {
 	defer test.Unlock()
 	// the the loop above we've created a single metric name with five different labels set ( host0, host1 .. host 4)
 	// let's see if we received all the 5 different labels.
-	require.Equal(t, 1, len(test.metrics), "Missing metric counts were reported.")
+	require.Equal(t, 1, len(test.metrics), "Missing metric counts were reported: %+v", test.metrics)
 
 	for k, v := range test.metrics {
 		// we have increased each one of the labels exactly 4 times. See that the counter was counting correctly.
@@ -163,11 +164,37 @@ func TestMetricCounterMixed(t *testing.T) {
 	defer test.Unlock()
 	// the the loop above we've created a single metric name with five different labels set ( host0, host1 .. host 4)
 	// let's see if we received all the 5 different labels.
-	require.Equal(t, 1, len(test.metrics), "Missing metric counts were reported.")
+	require.Equal(t, 1, len(test.metrics), "Missing metric counts were reported: %+v", test.metrics)
 
 	for k, v := range test.metrics {
 		// we have increased each one of the labels exactly 4 times. See that the counter was counting correctly.
 		// ( counters starts at zero )
 		require.Equal(t, "35.5", v, fmt.Sprintf("The metric '%s' reached value '%s'", k, v))
 	}
 }
+
+func TestCounterWriteMetric(t *testing.T) {
+	partitiontest.PartitionTest(t)
+
+	c := MakeCounter(MetricName{Name: "testname", Description: "testhelp"})
+	c.Deregister(nil)
+
+	// ensure 0 counters are still logged
+	sbOut := strings.Builder{}
+	c.WriteMetric(&sbOut, `host="myhost"`)
+	expected := `# HELP testname testhelp
+# TYPE testname counter
+testname{host="myhost"} 0
+`
+	require.Equal(t, expected, sbOut.String())
+
+	c.Add(2.3, nil)
+	// ensure non-zero counters are logged
+	sbOut = strings.Builder{}
+	c.WriteMetric(&sbOut, `host="myhost"`)
+	expected = `# HELP testname testhelp
+# TYPE testname counter
+testname{host="myhost"} 2.3
+`
+	require.Equal(t, expected, sbOut.String())
+}

util/metrics/gauge_test.go

@@ -68,7 +68,7 @@ func TestMetricGauge(t *testing.T) {
 
 	// the the loop above we've created a single metric name with five different labels set ( host0, host1 .. host 4)
 	// let's see if we received all the 5 different labels.
-	require.Equal(t, 5, len(test.metrics), "Missing metric counts were reported.")
+	require.Equal(t, 5, len(test.metrics), "Missing metric counts were reported: %+v", test.metrics)
 
 	// iterate through the metrics and check the each of the metrics reached it's correct count.
 	for k, v := range test.metrics {

util/metrics/registry_test.go

@@ -37,7 +37,7 @@ func TestWriteAdd(t *testing.T) {
 	results := make(map[string]float64)
 	DefaultRegistry().AddMetrics(results)
 
-	require.Equal(t, 2, len(results))
+	require.Equal(t, 2, len(results), "results", results)
 	require.Contains(t, results, "gauge-name")
 	require.InDelta(t, 12.34, results["gauge-name"], 0.01)
 	require.Contains(t, results, "label-counter_label__a_label_value_")