Metrics: expand coredns_dns_responses_total with plugin label (#4914)

* Metrics: expand coredns_dns_responses_total with plugin label

This adds (somewhat hacky?) code to add a plugin label to the
coredns_dns_responses_total metric. It's completely obvlious to the
plugin as we just check who called the *recorder.WriteMsg method. We use
runtime.Caller( 1 2 3) to get multiple levels of callers, this should be
deep enough, but it depends on the dns.ResponseWriter wrapping that's
occuring.

README.md of metrics updates and test added in test/metrics_test.go to
check for the label being set.

I went through the plugin to see what metrics could be removed, but
actually didn't find any, the plugin push out metrics that make sense.

Due to the path fiddling to figure out the plugin name I doubt this
works (out-of-the-box) for external plugins, but I haven't tested that.

Signed-off-by: Miek Gieben <miek@miek.nl>

* better comment

Signed-off-by: Miek Gieben <miek@miek.nl>

* Metrics: expand coredns_dns_responses_total with plugin label

This adds (somewhat hacky?) code to add a plugin label to the
coredns_dns_responses_total metric. It's completely obvlious to the
plugin as we just check who called the *recorder.WriteMsg method. We use
runtime.Caller( 1 2 3) to get multiple levels of callers, this should be
deep enough, but it depends on the dns.ResponseWriter wrapping that's
occuring.

README.md of metrics updates and test added in test/metrics_test.go to
check for the label being set.

I went through the plugin to see what metrics could be removed, but
actually didn't find any, the plugin push out metrics that make sense.

Due to the path fiddling to figure out the plugin name I doubt this
works (out-of-the-box) for external plugins, but I haven't tested that.

Signed-off-by: Miek Gieben <miek@miek.nl>

* Update core/dnsserver/server.go

Co-authored-by: dilyevsky <ilyevsky@gmail.com>

* Use [3]string

Signed-off-by: Miek Gieben <miek@miek.nl>

* imports

Signed-off-by: Miek Gieben <miek@miek.nl>

* remove dnstest changes

Signed-off-by: Miek Gieben <miek@miek.nl>

* revert

Signed-off-by: Miek Gieben <miek@miek.nl>

* Add some sleeps to make it less flaky

Signed-off-by: Miek Gieben <miek@miek.nl>

* Revert "Add some sleeps to make it less flaky"

This reverts commit b5c6655196e3ad570555f086832ceb1f48f6f2d5.

* Remove forward when not needed

Signed-off-by: Miek Gieben <miek@miek.nl>

* remove newline

Signed-off-by: Miek Gieben <miek@miek.nl>

Co-authored-by: dilyevsky <ilyevsky@gmail.com>

6 files changed, 71 insertions, 7 deletions

diff --git a/plugin/metrics/README.md b/plugin/metrics/README.md
index 602460f60..75c20bde9 100644
--- a/plugin/metrics/README.md
+++ b/plugin/metrics/README.md
@@ -17,7 +17,7 @@ The following metrics are exported:
 * `coredns_dns_request_size_bytes{server, zone, proto}` - size of the request in bytes.
 * `coredns_dns_do_requests_total{server, zone}` -  queries that have the DO bit set
 * `coredns_dns_response_size_bytes{server, zone, proto}` - response size in bytes.
-* `coredns_dns_responses_total{server, zone, rcode}` - response per zone and rcode.
+* `coredns_dns_responses_total{server, zone, rcode, plugin}` - response per zone, rcode and plugin.
 * `coredns_plugin_enabled{server, zone, name}` - indicates whether a plugin is enabled on per server and zone basis.
 
 Each counter has a label `zone` which is the zonename used for the request/response.
@@ -32,6 +32,8 @@ Extra labels used are:
 * `type` which holds the query type. It holds most common types (A, AAAA, MX, SOA, CNAME, PTR, TXT,
   NS, SRV, DS, DNSKEY, RRSIG, NSEC, NSEC3, HTTPS, IXFR, AXFR and ANY) and "other" which lumps together all
   other types.
+* the `plugin` label holds the name of the plugin that made the write to the client. If the server
+  did the write (on error for instance), the value is empty.
 
 If monitoring is enabled, queries that do not enter the plugin chain are exported under the fake
 name "dropped" (without a closing dot - this is never a valid domain name).
diff --git a/plugin/metrics/handler.go b/plugin/metrics/handler.go
index f26f90598..90db76181 100644
--- a/plugin/metrics/handler.go
+++ b/plugin/metrics/handler.go
@@ -2,10 +2,10 @@ package metrics
 
 import (
 	"context"
+	"path/filepath"
 
 	"github.com/coredns/coredns/plugin"
 	"github.com/coredns/coredns/plugin/metrics/vars"
-	"github.com/coredns/coredns/plugin/pkg/dnstest"
 	"github.com/coredns/coredns/plugin/pkg/rcode"
 	"github.com/coredns/coredns/request"
 
@@ -23,7 +23,7 @@ func (m *Metrics) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg
 	}
 
 	// Record response to get status code and size of the reply.
-	rw := dnstest.NewRecorder(w)
+	rw := NewRecorder(w)
 	status, err := plugin.NextOrFailure(m.Name(), m.Next, ctx, rw, r)
 
 	rc := rw.Rcode
@@ -33,10 +33,25 @@ func (m *Metrics) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg
 		// see https://github.com/coredns/coredns/blob/master/core/dnsserver/server.go#L318
 		rc = status
 	}
-	vars.Report(WithServer(ctx), state, zone, rcode.ToString(rc), rw.Len, rw.Start)
+	plugin := m.authoritativePlugin(rw.Caller)
+	vars.Report(WithServer(ctx), state, zone, rcode.ToString(rc), plugin, rw.Len, rw.Start)
 
 	return status, err
 }
 
 // Name implements the Handler interface.
 func (m *Metrics) Name() string { return "prometheus" }
+
+// authoritativePlugin returns which of made the write, if none is found the empty string is returned.
+func (m *Metrics) authoritativePlugin(caller [3]string) string {
+	// a b and c contain the full path of the caller, the plugin name 2nd last elements
+	// .../coredns/plugin/whoami/whoami.go --> whoami
+	// this is likely FS specific, so use filepath.
+	for _, c := range caller {
+		plug := filepath.Base(filepath.Dir(c))
+		if _, ok := m.plugins[plug]; ok {
+			return plug
+		}
+	}
+	return ""
+}
diff --git a/plugin/metrics/metrics.go b/plugin/metrics/metrics.go
index f6c1e6c8c..6a9e65272 100644
--- a/plugin/metrics/metrics.go
+++ b/plugin/metrics/metrics.go
@@ -8,6 +8,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/coredns/caddy"
 	"github.com/coredns/coredns/plugin"
 	"github.com/coredns/coredns/plugin/pkg/reuseport"
 
@@ -31,6 +32,8 @@ type Metrics struct {
 	zoneNames []string
 	zoneMap   map[string]struct{}
 	zoneMu    sync.RWMutex
+
+	plugins map[string]struct{} // all available plugins, used to determine which plugin made the client write
 }
 
 // New returns a new instance of Metrics with the given address.
@@ -39,6 +42,7 @@ func New(addr string) *Metrics {
 		Addr:    addr,
 		Reg:     prometheus.DefaultRegisterer.(*prometheus.Registry),
 		zoneMap: make(map[string]struct{}),
+		plugins: pluginList(caddy.ListPlugins()),
 	}
 
 	return met
@@ -140,6 +144,19 @@ func keys(m map[string]struct{}) []string {
 	return sx
 }
 
+// pluginList iterates over the returned plugin map from caddy and removes the "dns." prefix from them.
+func pluginList(m map[string][]string) map[string]struct{} {
+	pm := map[string]struct{}{}
+	for _, p := range m["others"] {
+		// only add 'dns.' plugins
+		if len(p) > 3 {
+			pm[p[4:]] = struct{}{}
+			continue
+		}
+	}
+	return pm
+}
+
 // ListenAddr is assigned the address of the prometheus listener. Its use is mainly in tests where
 // we listen on "localhost:0" and need to retrieve the actual address.
 var ListenAddr string
diff --git a/plugin/metrics/recorder.go b/plugin/metrics/recorder.go
new file mode 100644
index 000000000..a37f420d5
--- /dev/null
+++ b/plugin/metrics/recorder.go
@@ -0,0 +1,30 @@
+package metrics
+
+import (
+	"runtime"
+
+	"github.com/coredns/coredns/plugin/pkg/dnstest"
+
+	"github.com/miekg/dns"
+)
+
+// Recorder is a dnstest.Recorder specific to the metrics plugin.
+type Recorder struct {
+	*dnstest.Recorder
+	// CallerN holds the string return value of the call to runtime.Caller(N+1)
+	Caller [3]string
+}
+
+// NewRecorder makes and returns a new Recorder.
+func NewRecorder(w dns.ResponseWriter) *Recorder { return &Recorder{Recorder: dnstest.NewRecorder(w)} }
+
+// WriteMsg records the status code and calls the
+// underlying ResponseWriter's WriteMsg method.
+func (r *Recorder) WriteMsg(res *dns.Msg) error {
+	_, r.Caller[0], _, _ = runtime.Caller(1)
+	_, r.Caller[1], _, _ = runtime.Caller(2)
+	_, r.Caller[2], _, _ = runtime.Caller(3)
+	r.Len += res.Len()
+	r.Msg = res
+	return r.ResponseWriter.WriteMsg(res)
+}
diff --git a/plugin/metrics/vars/report.go b/plugin/metrics/vars/report.go
index 5aaff2f00..9761f626f 100644
--- a/plugin/metrics/vars/report.go
+++ b/plugin/metrics/vars/report.go
@@ -9,7 +9,7 @@ import (
 // Report reports the metrics data associated with request. This function is exported because it is also
 // called from core/dnsserver to report requests hitting the server that should not be handled and are thus
 // not sent down the plugin chain.
-func Report(server string, req request.Request, zone, rcode string, size int, start time.Time) {
+func Report(server string, req request.Request, zone, rcode, plugin string, size int, start time.Time) {
 	// Proto and Family.
 	net := req.Proto()
 	fam := "1"
@@ -29,5 +29,5 @@ func Report(server string, req request.Request, zone, rcode string, size int, st
 	ResponseSize.WithLabelValues(server, zone, net).Observe(float64(size))
 	RequestSize.WithLabelValues(server, zone, net).Observe(float64(req.Len()))
 
-	ResponseRcode.WithLabelValues(server, zone, rcode).Inc()
+	ResponseRcode.WithLabelValues(server, zone, rcode, plugin).Inc()
 }
diff --git a/plugin/metrics/vars/vars.go b/plugin/metrics/vars/vars.go
index 7a803a62a..1412bf16c 100644
--- a/plugin/metrics/vars/vars.go
+++ b/plugin/metrics/vars/vars.go
@@ -52,7 +52,7 @@ var (
 		Subsystem: subsystem,
 		Name:      "responses_total",
 		Help:      "Counter of response status codes.",
-	}, []string{"server", "zone", "rcode"})
+	}, []string{"server", "zone", "rcode", "plugin"})
 
 	Panic = promauto.NewCounter(prometheus.CounterOpts{
 		Namespace: plugin.Namespace,