Remove the word middleware (#1067)

* Rename middleware to plugin

first pass; mostly used 'sed', few spots where I manually changed
text.

This still builds a coredns binary.

* fmt error

* Rename AddMiddleware to AddPlugin

* Readd AddMiddleware to remain backwards compat

plugin/log/README.md

@@ -0,0 +1,102 @@
+# log
+
+*log* enables query logging to standard output.
+
+## Syntax
+
+~~~ txt
+log
+~~~
+
+* With no arguments, a query log entry is written to *stdout* in the common log format for all requests
+
+~~~ txt
+log FILE
+~~~
+
+* **FILE** is the log file to create (or append to). The *only* valid name for **FILE** is *stdout*.
+
+~~~ txt
+log [NAME] FILE [FORMAT]
+~~~
+
+* `NAME` is the name to match in order to be logged
+* `FILE` is the log file (again only *stdout* is allowed here).
+* `FORMAT` is the log format to use (default is Common Log Format)
+
+You can further specify the class of responses that get logged:
+
+~~~ txt
+log [NAME] FILE [FORMAT] {
+    class [success|denial|error|all]
+}
+~~~
+
+Here `success` `denial` and `error` denotes the class of responses that should be logged. The
+classes have the following meaning:
+
+* `success`: successful response
+* `denial`: either NXDOMAIN or NODATA (name exists, type does not)
+* `error`: SERVFAIL, NOTIMP, REFUSED, etc. Anything that indicates the remote server is not willing to
+    resolve the request.
+* `all`: the default - nothing is specified.
+
+If no class is specified, it defaults to *all*.
+
+## Log File
+
+The "log file" can only be *stdout*. CoreDNS expects another service to pick up this output and deal
+with it, i.e. journald when using systemd or Docker's logging capabilities.
+
+## Log Format
+
+You can specify a custom log format with any placeholder values. Log supports both request and
+response placeholders.
+
+The following place holders are supported:
+
+* `{type}`: qtype of the request
+* `{name}`: qname of the request
+* `{class}`: qclass of the request
+* `{proto}`: protocol used (tcp or udp)
+* `{when}`: time of the query
+* `{remote}`: client's IP address
+* `{size}`: request size in bytes
+* `{port}`: client's port
+* `{duration}`: response duration
+* `{rcode}`: response RCODE
+* `{rsize}`: response size
+* `{>rflags}`: response flags, each set flag will be displayed, e.g. "aa, tc". This includes the qr
+  bit as well.
+* `{>bufsize}`: the EDNS0 buffer size advertised in the query
+* `{>do}`: is the EDNS0 DO (DNSSEC OK) bit set in the query
+* `{>id}`: query ID
+* `{>opcode}`: query OPCODE
+
+The default Common Log Format is:
+
+~~~ txt
+`{remote} - [{when}] "{type} {class} {name} {proto} {size} {>do} {>bufsize}" {rcode} {>rflags} {rsize} {duration}`
+~~~
+
+## Examples
+
+Log all requests to stdout
+
+~~~
+log stdout
+~~~
+
+Custom log format, for all zones (`.`)
+
+~~~
+log . stdout "{proto} Request: {name} {type} {>id}"
+~~~
+
+Only log denials for example.org (and below to a file)
+
+~~~
+log example.org stdout {
+    class denial
+}
+~~~

plugin/log/log.go

@@ -0,0 +1,91 @@
+// Package log implements basic but useful request (access) logging plugin.
+package log
+
+import (
+	"log"
+	"time"
+
+	"github.com/coredns/coredns/plugin"
+	"github.com/coredns/coredns/plugin/metrics/vars"
+	"github.com/coredns/coredns/plugin/pkg/dnsrecorder"
+	"github.com/coredns/coredns/plugin/pkg/rcode"
+	"github.com/coredns/coredns/plugin/pkg/replacer"
+	"github.com/coredns/coredns/plugin/pkg/response"
+	"github.com/coredns/coredns/request"
+
+	"github.com/miekg/dns"
+	"golang.org/x/net/context"
+)
+
+// Logger is a basic request logging plugin.
+type Logger struct {
+	Next      plugin.Handler
+	Rules     []Rule
+	ErrorFunc func(dns.ResponseWriter, *dns.Msg, int) // failover error handler
+}
+
+// ServeDNS implements the plugin.Handler interface.
+func (l Logger) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) (int, error) {
+	state := request.Request{W: w, Req: r}
+	for _, rule := range l.Rules {
+		if !plugin.Name(rule.NameScope).Matches(state.Name()) {
+			continue
+		}
+
+		rrw := dnsrecorder.New(w)
+		rc, err := plugin.NextOrFailure(l.Name(), l.Next, ctx, rrw, r)
+
+		if rc > 0 {
+			// There was an error up the chain, but no response has been written yet.
+			// The error must be handled here so the log entry will record the response size.
+			if l.ErrorFunc != nil {
+				l.ErrorFunc(rrw, r, rc)
+			} else {
+				answer := new(dns.Msg)
+				answer.SetRcode(r, rc)
+				state.SizeAndDo(answer)
+
+				vars.Report(state, vars.Dropped, rcode.ToString(rc), answer.Len(), time.Now())
+
+				w.WriteMsg(answer)
+			}
+			rc = 0
+		}
+
+		tpe, _ := response.Typify(rrw.Msg, time.Now().UTC())
+		class := response.Classify(tpe)
+		if rule.Class == response.All || rule.Class == class {
+			rep := replacer.New(r, rrw, CommonLogEmptyValue)
+			rule.Log.Println(rep.Replace(rule.Format))
+		}
+
+		return rc, err
+
+	}
+	return plugin.NextOrFailure(l.Name(), l.Next, ctx, w, r)
+}
+
+// Name implements the Handler interface.
+func (l Logger) Name() string { return "log" }
+
+// Rule configures the logging plugin.
+type Rule struct {
+	NameScope  string
+	Class      response.Class
+	OutputFile string
+	Format     string
+	Log        *log.Logger
+}
+
+const (
+	// DefaultLogFilename is the default output name. This is the only supported value.
+	DefaultLogFilename = "stdout"
+	// CommonLogFormat is the common log format.
+	CommonLogFormat = `{remote} ` + CommonLogEmptyValue + ` [{when}] "{type} {class} {name} {proto} {size} {>do} {>bufsize}" {rcode} {>rflags} {rsize} {duration}`
+	// CommonLogEmptyValue is the common empty log value.
+	CommonLogEmptyValue = "-"
+	// CombinedLogFormat is the combined log format.
+	CombinedLogFormat = CommonLogFormat + ` "{>opcode}"`
+	// DefaultLogFormat is the default log format.
+	DefaultLogFormat = CommonLogFormat
+)

plugin/log/log_test.go

@@ -0,0 +1,101 @@
+package log
+
+import (
+	"bytes"
+	"log"
+	"strings"
+	"testing"
+
+	"github.com/coredns/coredns/plugin/pkg/dnsrecorder"
+	"github.com/coredns/coredns/plugin/pkg/response"
+	"github.com/coredns/coredns/plugin/test"
+
+	"github.com/miekg/dns"
+	"golang.org/x/net/context"
+)
+
+func TestLoggedStatus(t *testing.T) {
+	var f bytes.Buffer
+	rule := Rule{
+		NameScope: ".",
+		Format:    DefaultLogFormat,
+		Log:       log.New(&f, "", 0),
+	}
+
+	logger := Logger{
+		Rules: []Rule{rule},
+		Next:  test.ErrorHandler(),
+	}
+
+	ctx := context.TODO()
+	r := new(dns.Msg)
+	r.SetQuestion("example.org.", dns.TypeA)
+
+	rec := dnsrecorder.New(&test.ResponseWriter{})
+
+	rcode, _ := logger.ServeDNS(ctx, rec, r)
+	if rcode != 0 {
+		t.Errorf("Expected rcode to be 0 - was: %d", rcode)
+	}
+
+	logged := f.String()
+	if !strings.Contains(logged, "A IN example.org. udp 29 false 512") {
+		t.Errorf("Expected it to be logged. Logged string: %s", logged)
+	}
+}
+
+func TestLoggedClassDenial(t *testing.T) {
+	var f bytes.Buffer
+	rule := Rule{
+		NameScope: ".",
+		Format:    DefaultLogFormat,
+		Log:       log.New(&f, "", 0),
+		Class:     response.Denial,
+	}
+
+	logger := Logger{
+		Rules: []Rule{rule},
+		Next:  test.ErrorHandler(),
+	}
+
+	ctx := context.TODO()
+	r := new(dns.Msg)
+	r.SetQuestion("example.org.", dns.TypeA)
+
+	rec := dnsrecorder.New(&test.ResponseWriter{})
+
+	logger.ServeDNS(ctx, rec, r)
+
+	logged := f.String()
+	if len(logged) != 0 {
+		t.Errorf("Expected it not to be logged, but got string: %s", logged)
+	}
+}
+
+func TestLoggedClassError(t *testing.T) {
+	var f bytes.Buffer
+	rule := Rule{
+		NameScope: ".",
+		Format:    DefaultLogFormat,
+		Log:       log.New(&f, "", 0),
+		Class:     response.Error,
+	}
+
+	logger := Logger{
+		Rules: []Rule{rule},
+		Next:  test.ErrorHandler(),
+	}
+
+	ctx := context.TODO()
+	r := new(dns.Msg)
+	r.SetQuestion("example.org.", dns.TypeA)
+
+	rec := dnsrecorder.New(&test.ResponseWriter{})
+
+	logger.ServeDNS(ctx, rec, r)
+
+	logged := f.String()
+	if !strings.Contains(logged, "SERVFAIL") {
+		t.Errorf("Expected it to be logged. Logged string: %s", logged)
+	}
+}

plugin/log/setup.go

@@ -0,0 +1,116 @@
+package log
+
+import (
+	"fmt"
+	"log"
+	"os"
+
+	"github.com/coredns/coredns/core/dnsserver"
+	"github.com/coredns/coredns/plugin"
+	"github.com/coredns/coredns/plugin/pkg/response"
+
+	"github.com/mholt/caddy"
+	"github.com/miekg/dns"
+)
+
+func init() {
+	caddy.RegisterPlugin("log", caddy.Plugin{
+		ServerType: "dns",
+		Action:     setup,
+	})
+}
+
+func setup(c *caddy.Controller) error {
+	rules, err := logParse(c)
+	if err != nil {
+		return plugin.Error("log", err)
+	}
+
+	// Open the log files for writing when the server starts
+	c.OnStartup(func() error {
+		for i := 0; i < len(rules); i++ {
+			// We only support stdout
+			writer := os.Stdout
+			if rules[i].OutputFile != "stdout" {
+				return plugin.Error("log", fmt.Errorf("invalid log file: %s", rules[i].OutputFile))
+			}
+
+			rules[i].Log = log.New(writer, "", 0)
+		}
+
+		return nil
+	})
+
+	dnsserver.GetConfig(c).AddPlugin(func(next plugin.Handler) plugin.Handler {
+		return Logger{Next: next, Rules: rules, ErrorFunc: dnsserver.DefaultErrorFunc}
+	})
+
+	return nil
+}
+
+func logParse(c *caddy.Controller) ([]Rule, error) {
+	var rules []Rule
+
+	for c.Next() {
+		args := c.RemainingArgs()
+
+		if len(args) == 0 {
+			// Nothing specified; use defaults
+			rules = append(rules, Rule{
+				NameScope:  ".",
+				OutputFile: DefaultLogFilename,
+				Format:     DefaultLogFormat,
+			})
+		} else if len(args) == 1 {
+			// Only an output file specified.
+			rules = append(rules, Rule{
+				NameScope:  ".",
+				OutputFile: args[0],
+				Format:     DefaultLogFormat,
+			})
+		} else {
+			// Name scope, output file, and maybe a format specified
+
+			format := DefaultLogFormat
+
+			if len(args) > 2 {
+				switch args[2] {
+				case "{common}":
+					format = CommonLogFormat
+				case "{combined}":
+					format = CombinedLogFormat
+				default:
+					format = args[2]
+				}
+			}
+
+			rules = append(rules, Rule{
+				NameScope:  dns.Fqdn(args[0]),
+				OutputFile: args[1],
+				Format:     format,
+			})
+		}
+
+		// Class refinements in an extra block.
+		for c.NextBlock() {
+			switch c.Val() {
+			// class followed by all, denial, error or success.
+			case "class":
+				classes := c.RemainingArgs()
+				if len(classes) == 0 {
+					return nil, c.ArgErr()
+				}
+				cls, err := response.ClassFromString(classes[0])
+				if err != nil {
+					return nil, err
+				}
+				// update class and the last added Rule (bit icky)
+				rules[len(rules)-1].Class = cls
+			default:
+				return nil, c.ArgErr()
+			}
+		}
+	}
+
+	return rules, nil
+}

plugin/log/setup_test.go

@@ -0,0 +1,130 @@
+package log
+
+import (
+	"testing"
+
+	"github.com/coredns/coredns/plugin/pkg/response"
+
+	"github.com/mholt/caddy"
+)
+
+func TestLogParse(t *testing.T) {
+	tests := []struct {
+		inputLogRules    string
+		shouldErr        bool
+		expectedLogRules []Rule
+	}{
+		{`log`, false, []Rule{{
+			NameScope:  ".",
+			OutputFile: DefaultLogFilename,
+			Format:     DefaultLogFormat,
+		}}},
+		{`log log.txt`, false, []Rule{{
+			NameScope:  ".",
+			OutputFile: "log.txt",
+			Format:     DefaultLogFormat,
+		}}},
+		{`log example.org log.txt`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "log.txt",
+			Format:     DefaultLogFormat,
+		}}},
+		{`log example.org. stdout`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "stdout",
+			Format:     DefaultLogFormat,
+		}}},
+		{`log example.org log.txt {common}`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "log.txt",
+			Format:     CommonLogFormat,
+		}}},
+		{`log example.org accesslog.txt {combined}`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "accesslog.txt",
+			Format:     CombinedLogFormat,
+		}}},
+		{`log example.org. log.txt
+		log example.net accesslog.txt {combined}`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "log.txt",
+			Format:     DefaultLogFormat,
+		}, {
+			NameScope:  "example.net.",
+			OutputFile: "accesslog.txt",
+			Format:     CombinedLogFormat,
+		}}},
+		{`log example.org stdout {host}
+			  log example.org log.txt {when}`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "stdout",
+			Format:     "{host}",
+		}, {
+			NameScope:  "example.org.",
+			OutputFile: "log.txt",
+			Format:     "{when}",
+		}}},
+
+		{`log example.org log.txt {
+				class all
+			}`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "log.txt",
+			Format:     CommonLogFormat,
+			Class:      response.All,
+		}}},
+		{`log example.org log.txt {
+			class denial
+		}`, false, []Rule{{
+			NameScope:  "example.org.",
+			OutputFile: "log.txt",
+			Format:     CommonLogFormat,
+			Class:      response.Denial,
+		}}},
+		{`log {
+			class denial
+		}`, false, []Rule{{
+			NameScope:  ".",
+			OutputFile: DefaultLogFilename,
+			Format:     CommonLogFormat,
+			Class:      response.Denial,
+		}}},
+	}
+	for i, test := range tests {
+		c := caddy.NewTestController("dns", test.inputLogRules)
+		actualLogRules, err := logParse(c)
+
+		if err == nil && test.shouldErr {
+			t.Errorf("Test %d didn't error, but it should have", i)
+		} else if err != nil && !test.shouldErr {
+			t.Errorf("Test %d errored, but it shouldn't have; got '%v'", i, err)
+		}
+		if len(actualLogRules) != len(test.expectedLogRules) {
+			t.Fatalf("Test %d expected %d no of Log rules, but got %d ",
+				i, len(test.expectedLogRules), len(actualLogRules))
+		}
+		for j, actualLogRule := range actualLogRules {
+
+			if actualLogRule.NameScope != test.expectedLogRules[j].NameScope {
+				t.Errorf("Test %d expected %dth LogRule NameScope to be  %s  , but got %s",
+					i, j, test.expectedLogRules[j].NameScope, actualLogRule.NameScope)
+			}
+
+			if actualLogRule.OutputFile != test.expectedLogRules[j].OutputFile {
+				t.Errorf("Test %d expected %dth LogRule OutputFile to be  %s  , but got %s",
+					i, j, test.expectedLogRules[j].OutputFile, actualLogRule.OutputFile)
+			}
+
+			if actualLogRule.Format != test.expectedLogRules[j].Format {
+				t.Errorf("Test %d expected %dth LogRule Format to be  %s  , but got %s",
+					i, j, test.expectedLogRules[j].Format, actualLogRule.Format)
+			}
+
+			if actualLogRule.Class != test.expectedLogRules[j].Class {
+				t.Errorf("Test %d expected %dth LogRule Class to be  %s  , but got %s",
+					i, j, test.expectedLogRules[j].Class, actualLogRule.Class)
+			}
+		}
+	}
+
+}