From e47d881461a947dbcc1d285d8a8d9f6a79e77fd7 Mon Sep 17 00:00:00 2001 From: Miek Gieben Date: Tue, 12 Feb 2019 07:38:49 +0000 Subject: [PATCH] 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 * Stickler bot Signed-off-by: Miek Gieben * Improve test coverage Signed-off-by: Miek Gieben * typo Signed-off-by: Miek Gieben * Add test for malformed log lines Signed-off-by: Miek Gieben --- plugin/log/log.go | 10 +- plugin/log/log_test.go | 6 + plugin/log/setup.go | 3 +- plugin/pkg/replacer/replacer.go | 219 ++++++++++++++------------- plugin/pkg/replacer/replacer_test.go | 180 ++++++++++++++-------- plugin/rewrite/condition.go | 10 +- 6 files changed, 254 insertions(+), 174 deletions(-) diff --git a/plugin/log/log.go b/plugin/log/log.go index 327bbf032..2489e03d1 100644 --- a/plugin/log/log.go +++ b/plugin/log/log.go @@ -22,6 +22,8 @@ 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. @@ -58,8 +60,8 @@ func (l Logger) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns.Msg) _, ok := rule.Class[response.All] _, ok1 := rule.Class[class] if ok || ok1 { - rep := replacer.New(ctx, r, rrw, CommonLogEmptyValue) - clog.Infof(rep.Replace(rule.Format)) + logstr := l.repl.Replace(ctx, state, rrw, rule.Format) + clog.Infof(logstr) } return rc, err @@ -80,9 +82,7 @@ type Rule struct { const ( // CommonLogFormat is the common log format. - CommonLogFormat = `{remote}:{port} ` + CommonLogEmptyValue + ` {>id} "{type} {class} {name} {proto} {size} {>do} {>bufsize}" {rcode} {>rflags} {rsize} {duration}` - // CommonLogEmptyValue is the common empty log value. - CommonLogEmptyValue = "-" + 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. diff --git a/plugin/log/log_test.go b/plugin/log/log_test.go index fd7bc1e8f..97e2b8c71 100644 --- a/plugin/log/log_test.go +++ b/plugin/log/log_test.go @@ -9,6 +9,7 @@ import ( "github.com/coredns/coredns/plugin/pkg/dnstest" clog "github.com/coredns/coredns/plugin/pkg/log" + "github.com/coredns/coredns/plugin/pkg/replacer" "github.com/coredns/coredns/plugin/pkg/response" "github.com/coredns/coredns/plugin/test" @@ -30,6 +31,7 @@ func TestLoggedStatus(t *testing.T) { logger := Logger{ Rules: []Rule{rule}, Next: test.ErrorHandler(), + repl: replacer.New(), } ctx := context.TODO() @@ -62,6 +64,7 @@ func TestLoggedClassDenial(t *testing.T) { logger := Logger{ Rules: []Rule{rule}, Next: test.ErrorHandler(), + repl: replacer.New(), } ctx := context.TODO() @@ -91,6 +94,7 @@ func TestLoggedClassError(t *testing.T) { logger := Logger{ Rules: []Rule{rule}, Next: test.ErrorHandler(), + repl: replacer.New(), } ctx := context.TODO() @@ -206,6 +210,7 @@ func TestLogged(t *testing.T) { logger := Logger{ Rules: tc.Rules, Next: test.ErrorHandler(), + repl: replacer.New(), } ctx := context.TODO() @@ -246,6 +251,7 @@ func BenchmarkLogged(b *testing.B) { logger := Logger{ Rules: []Rule{rule}, Next: test.ErrorHandler(), + repl: replacer.New(), } ctx := context.TODO() diff --git a/plugin/log/setup.go b/plugin/log/setup.go index 6f92fca3d..81a2004f2 100644 --- a/plugin/log/setup.go +++ b/plugin/log/setup.go @@ -5,6 +5,7 @@ import ( "github.com/coredns/coredns/core/dnsserver" "github.com/coredns/coredns/plugin" + "github.com/coredns/coredns/plugin/pkg/replacer" "github.com/coredns/coredns/plugin/pkg/response" "github.com/mholt/caddy" @@ -25,7 +26,7 @@ func setup(c *caddy.Controller) error { } dnsserver.GetConfig(c).AddPlugin(func(next plugin.Handler) plugin.Handler { - return Logger{Next: next, Rules: rules, ErrorFunc: dnsserver.DefaultErrorFunc} + return Logger{Next: next, Rules: rules, ErrorFunc: dnsserver.DefaultErrorFunc, repl: replacer.New()} }) return nil diff --git a/plugin/pkg/replacer/replacer.go b/plugin/pkg/replacer/replacer.go index 8c8032c76..f72e1ec9c 100644 --- a/plugin/pkg/replacer/replacer.go +++ b/plugin/pkg/replacer/replacer.go @@ -13,123 +13,134 @@ import ( "github.com/miekg/dns" ) -// Replacer is a type which can replace placeholder -// substrings in a string with actual values from a -// dns.Msg and responseRecorder. Always use -// NewReplacer to get one of these. -type Replacer interface { - Replace(string) string - Set(key, value string) +// Replacer replaces labels for values in strings. +type Replacer struct { + valueFunc func(request.Request, *dnstest.Recorder, string) string + labels []string } -type replacer struct { - ctx context.Context - replacements map[string]string - emptyValue string +// labels are all supported labels that can be used in the default Replacer. +var labels = []string{ + "{type}", + "{name}", + "{class}", + "{proto}", + "{size}", + "{remote}", + "{port}", + "{local}", + // Header values. + headerReplacer + "id}", + headerReplacer + "opcode}", + headerReplacer + "do}", + headerReplacer + "bufsize}", + // Recorded replacements. + "{rcode}", + "{rsize}", + "{duration}", + headerReplacer + "rrflags}", } -// New makes a new replacer based on r and rr. -// Do not create a new replacer until r and rr have all -// the needed values, because this function copies those -// values into the replacer. rr may be nil if it is not -// available. emptyValue should be the string that is used -// in place of empty string (can still be empty string). -func New(ctx context.Context, r *dns.Msg, rr *dnstest.Recorder, emptyValue string) Replacer { - req := request.Request{W: rr, Req: r} - rep := replacer{ - ctx: ctx, - replacements: map[string]string{ - "{type}": req.Type(), - "{name}": req.Name(), - "{class}": req.Class(), - "{proto}": req.Proto(), - "{when}": "", // made a noop - "{size}": strconv.Itoa(req.Len()), - "{remote}": addrToRFC3986(req.IP()), - "{port}": req.Port(), - "{local}": addrToRFC3986(req.LocalIP()), - }, - emptyValue: emptyValue, - } - if rr != nil { +// value returns the current value of label. +func value(state request.Request, rr *dnstest.Recorder, label string) string { + switch label { + case "{type}": + return state.Type() + case "{name}": + return state.Name() + case "{class}": + return state.Class() + case "{proto}": + return state.Proto() + case "{size}": + return strconv.Itoa(state.Req.Len()) + case "{remote}": + return addrToRFC3986(state.IP()) + case "{port}": + return state.Port() + case "{local}": + return addrToRFC3986(state.LocalIP()) + // Header placeholders (case-insensitive). + case headerReplacer + "id}": + return strconv.Itoa(int(state.Req.Id)) + case headerReplacer + "opcode}": + return strconv.Itoa(state.Req.Opcode) + case headerReplacer + "do}": + return boolToString(state.Do()) + case headerReplacer + "bufsize}": + return strconv.Itoa(state.Size()) + // Recorded replacements. + case "{rcode}": + if rr == nil { + return EmptyValue + } rcode := dns.RcodeToString[rr.Rcode] if rcode == "" { rcode = strconv.Itoa(rr.Rcode) } - rep.replacements["{rcode}"] = rcode - rep.replacements["{rsize}"] = strconv.Itoa(rr.Len) - rep.replacements["{duration}"] = strconv.FormatFloat(time.Since(rr.Start).Seconds(), 'f', -1, 64) + "s" - if rr.Msg != nil { - rep.replacements[headerReplacer+"rflags}"] = flagsToString(rr.Msg.MsgHdr) + return rcode + case "{rsize}": + if rr == nil { + return EmptyValue + } + return strconv.Itoa(rr.Len) + case "{duration}": + if rr == nil { + return EmptyValue + } + return strconv.FormatFloat(time.Since(rr.Start).Seconds(), 'f', -1, 64) + "s" + case headerReplacer + "rrflags}": + if rr != nil && rr.Msg != nil { + return flagsToString(rr.Msg.MsgHdr) + } + return EmptyValue + } + return EmptyValue +} + +// New makes a new replacer. This only needs to be called once in the setup and then call Replace for each incoming message. +// A replacer is safe for concurrent use. +func New() Replacer { + return Replacer{ + valueFunc: value, + labels: labels, + } +} + +// Replace performs a replacement of values on s and returns the string with the replaced values. +func (r Replacer) Replace(ctx context.Context, state request.Request, rr *dnstest.Recorder, s string) string { + for _, placeholder := range r.labels { + if strings.Contains(s, placeholder) { + s = strings.Replace(s, placeholder, r.valueFunc(state, rr, placeholder), -1) } } - // Header placeholders (case-insensitive) - rep.replacements[headerReplacer+"id}"] = strconv.Itoa(int(r.Id)) - rep.replacements[headerReplacer+"opcode}"] = strconv.Itoa(r.Opcode) - rep.replacements[headerReplacer+"do}"] = boolToString(req.Do()) - rep.replacements[headerReplacer+"bufsize}"] = strconv.Itoa(req.Size()) + // Metadata label replacements. Scan for {/ and search for next }, replace that metadata label with + // any meta data that is available. + b := strings.Builder{} + for strings.Contains(s, labelReplacer) { + idxStart := strings.Index(s, labelReplacer) + endOffset := idxStart + len(labelReplacer) + idxEnd := strings.Index(s[endOffset:], "}") + if idxEnd > -1 { + label := s[idxStart+2 : endOffset+idxEnd] - return rep -} - -// Replace performs a replacement of values on s and returns -// the string with the replaced values. -func (r replacer) Replace(s string) string { - - // declare a function that replace based on header matching - fscanAndReplace := func(s string, header string, replace func(string) string) string { - b := strings.Builder{} - for strings.Contains(s, header) { - idxStart := strings.Index(s, header) - endOffset := idxStart + len(header) - idxEnd := strings.Index(s[endOffset:], "}") - if idxEnd > -1 { - placeholder := strings.ToLower(s[idxStart : endOffset+idxEnd+1]) - replacement := replace(placeholder) - if replacement == "" { - replacement = r.emptyValue - } - b.WriteString(s[:idxStart]) - b.WriteString(replacement) - s = s[endOffset+idxEnd+1:] - } else { - break + fm := metadata.ValueFunc(ctx, label) + replacement := EmptyValue + if fm != nil { + replacement = fm() } + + b.WriteString(s[:idxStart]) + b.WriteString(replacement) + s = s[endOffset+idxEnd+1:] + } else { + break } - b.WriteString(s) - return b.String() } - // Header replacements - these are case-insensitive, so we can't just use strings.Replace() - s = fscanAndReplace(s, headerReplacer, func(placeholder string) string { - return r.replacements[placeholder] - }) - - // Regular replacements - these are easier because they're case-sensitive - for placeholder, replacement := range r.replacements { - if replacement == "" { - replacement = r.emptyValue - } - s = strings.Replace(s, placeholder, replacement, -1) - } - - // Metadata label replacements - s = fscanAndReplace(s, headerLabelReplacer, func(placeholder string) string { - // label place holder has the format {/