coredns/plugin/log/log.go
Miek Gieben e47d881461
pkg/replace: make it more efficient. (#2544)
* pkg/replace: make it more efficient.

Remove the map that is allocated on every write and make it more static,
but just defining a function that gets called for a label and returns
its value.

Remove the interface definition and just implement what is needed in our
case. Add benchmark test for replace as well.

Extend metadata test to test multiple values (pretty sure this didn't
work, but there wasn't a test for it, so can't be sure).

Update all callers to use it - concurrent use should be fine as we pass
everything by value.

Benchmarks in replacer:

new: BenchmarkReplacer-4   300000      4717 ns/op     240 B/op       8 allocs/op
old: BenchmarkReplacer-4   300000      4368 ns/op     384 B/op      11 allocs/op

Added benchmark function to the old code to test it.

~~~
func BenchmarkReplacer(b *testing.B) {
	w := dnstest.NewRecorder(&test.ResponseWriter{})
	r := new(dns.Msg)
	r.SetQuestion("example.org.", dns.TypeHINFO)
	r.MsgHdr.AuthenticatedData = true
	b.ResetTimer()
	b.ReportAllocs()
	repl := New(context.TODO(), r, w, "")
	for i := 0; i < b.N; i++ {
		repl.Replace("{type} {name} {size}")
	}
}
~~~

New code contains (of course a different one). The amount of ops is
more, which might be good to look at some more. For all the allocations
is seems it was quite performant.

This looks to be 50% faster, and there is less allocations in log
plugin:

old: BenchmarkLogged-4   	   20000	     70526 ns/op
new: BenchmarkLogged-4   	   30000	     57558 ns/op

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

* Stickler bot

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

* Improve test coverage

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

* typo

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

* Add test for malformed log lines

Signed-off-by: Miek Gieben <miek@miek.nl>
2019-02-12 07:38:49 +00:00

90 lines
2.6 KiB
Go

// Package log implements basic but useful request (access) logging plugin.
package log
import (
"context"
"time"
"github.com/coredns/coredns/plugin"
"github.com/coredns/coredns/plugin/metrics/vars"
"github.com/coredns/coredns/plugin/pkg/dnstest"
clog "github.com/coredns/coredns/plugin/pkg/log"
"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"
)
// Logger is a basic request logging plugin.
type Logger struct {
Next plugin.Handler
Rules []Rule
ErrorFunc func(context.Context, dns.ResponseWriter, *dns.Msg, int) // failover error handler
repl replacer.Replacer
}
// 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 := dnstest.NewRecorder(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(ctx, rrw, r, rc)
} else {
answer := new(dns.Msg)
answer.SetRcode(r, rc)
vars.Report(ctx, 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 we don't set up a class in config, the default "all" will be added
// and we shouldn't have an empty rule.Class.
_, ok := rule.Class[response.All]
_, ok1 := rule.Class[class]
if ok || ok1 {
logstr := l.repl.Replace(ctx, state, rrw, rule.Format)
clog.Infof(logstr)
}
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 map[response.Class]struct{}
Format string
}
const (
// CommonLogFormat is the common log format.
CommonLogFormat = `{remote}:{port} ` + replacer.EmptyValue + ` {>id} "{type} {class} {name} {proto} {size} {>do} {>bufsize}" {rcode} {>rflags} {rsize} {duration}`
// CombinedLogFormat is the combined log format.
CombinedLogFormat = CommonLogFormat + ` "{>opcode}"`
// DefaultLogFormat is the default log format.
DefaultLogFormat = CommonLogFormat
)