TrueCloudLab/coredns
16
0
Fork 2
Code Issues Pull requests 4 Projects Releases Packages Wiki Activity Actions

pkg/replace: make it more efficient. (#2544)

Browse source 
* 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>
This commit is contained in:
Miek Gieben 2019-02-12 07:38:49 +00:00 • committed by GitHub
parent 29cb00aada
commit e47d881461
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 254 additions and 174 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

10
plugin/log/log.go
View file

@ -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.

6
plugin/log/log_test.go
View file

@ -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()

3
plugin/log/setup.go
View file

@ -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

219
plugin/pkg/replacer/replacer.go
View file

@ -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 {/<label>}
fm := metadata.ValueFunc(r.ctx, placeholder[len(headerLabelReplacer):len(placeholder)-1])
if fm != nil {
return fm()
}
return ""
})
return s
}
// Set sets key to value in the replacements map.
func (r replacer) Set(key, value string) {
r.replacements["{"+key+"}"] = value
b.WriteString(s)
return b.String()
}
func boolToString(b bool) string {
@ -190,6 +201,8 @@ func addrToRFC3986(addr string) string {
}
const (
headerReplacer = "{>"
headerLabelReplacer = "{/"
headerReplacer = "{>"
labelReplacer = "{/"
// EmptyValue is the default empty value.
EmptyValue = "-"
)

180
plugin/pkg/replacer/replacer_test.go
View file

@ -2,69 +2,99 @@ package replacer
import (
"context"
"strings"
"testing"
"github.com/coredns/coredns/plugin/metadata"
"github.com/coredns/coredns/request"
"github.com/coredns/coredns/plugin/pkg/dnstest"
"github.com/coredns/coredns/plugin/test"
"github.com/coredns/coredns/request"
"github.com/miekg/dns"
)
func TestNewReplacer(t *testing.T) {
func TestReplacer(t *testing.T) {
w := dnstest.NewRecorder(&test.ResponseWriter{})
r := new(dns.Msg)
r.SetQuestion("example.org.", dns.TypeHINFO)
r.MsgHdr.AuthenticatedData = true
state := request.Request{W: w, Req: r}
replaceValues := New(context.TODO(), r, w, "")
replacer := New()
switch v := replaceValues.(type) {
case replacer:
if v.replacements["{type}"] != "HINFO" {
t.Errorf("Expected type to be HINFO, got %q", v.replacements["{type}"])
}
if v.replacements["{name}"] != "example.org." {
t.Errorf("Expected request name to be example.org., got %q", v.replacements["{name}"])
}
if v.replacements["{size}"] != "29" { // size of request
t.Errorf("Expected size to be 29, got %q", v.replacements["{size}"])
}
if !strings.Contains(v.replacements["{duration}"], "s") {
t.Errorf("Expected units of time to be in seconds")
}
default:
t.Fatal("Return Value from New Replacer expected pass type assertion into a replacer type\n")
if x := replacer.Replace(context.TODO(), state, nil, "{type}"); x != "HINFO" {
t.Errorf("Expected type to be HINFO, got %q", x)
}
if x := replacer.Replace(context.TODO(), state, nil, "{name}"); x != "example.org." {
t.Errorf("Expected request name to be example.org., got %q", x)
}
if x := replacer.Replace(context.TODO(), state, nil, "{size}"); x != "29" {
t.Errorf("Expected size to be 29, got %q", x)
}
}
func TestSet(t *testing.T) {
func TestLabels(t *testing.T) {
w := dnstest.NewRecorder(&test.ResponseWriter{})
r := new(dns.Msg)
r.SetQuestion("example.org.", dns.TypeHINFO)
r.Id = 1053
r.AuthenticatedData = true
r.CheckingDisabled = true
w.WriteMsg(r)
state := request.Request{W: w, Req: r}
replacer := New()
ctx := context.TODO()
// This couples the test very tightly to the code, but so be it.
expect := map[string]string{
"{type}": "HINFO",
"{name}": "example.org.",
"{class}": "IN",
"{proto}": "udp",
"{size}": "29",
"{remote}": "10.240.0.1",
"{port}": "40212",
"{local}": "127.0.0.1",
headerReplacer + "id}": "1053",
headerReplacer + "opcode}": "0",
headerReplacer + "do}": "false",
headerReplacer + "bufsize}": "512",
"{rcode}": "NOERROR",
"{rsize}": "29",
"{duration}": "0",
headerReplacer + "rrflags}": "rd,ad,cd",
}
if len(expect) != len(labels) {
t.Fatalf("Expect %d labels, got %d", len(expect), len(labels))
}
for _, lbl := range labels {
repl := replacer.Replace(ctx, state, w, lbl)
if lbl == "{duration}" {
if repl[len(repl)-1] != 's' {
t.Errorf("Expected seconds, got %q", repl)
}
continue
}
if repl != expect[lbl] {
t.Errorf("Expected value %q, got %q", expect[lbl], repl)
}
}
}
func BenchmarkReplacer(b *testing.B) {
w := dnstest.NewRecorder(&test.ResponseWriter{})
r := new(dns.Msg)
r.SetQuestion("example.org.", dns.TypeHINFO)
r.MsgHdr.AuthenticatedData = true
state := request.Request{W: w, Req: r}
repl := New(context.TODO(), r, w, "")
b.ResetTimer()
b.ReportAllocs()
repl.Set("name", "coredns.io.")
repl.Set("type", "A")
repl.Set("size", "20")
if repl.Replace("This name is {name}") != "This name is coredns.io." {
t.Error("Expected name replacement failed")
}
if repl.Replace("This type is {type}") != "This type is A" {
t.Error("Expected type replacement failed")
}
if repl.Replace("The request size is {size}") != "The request size is 20" {
t.Error("Expected size replacement failed")
replacer := New()
for i := 0; i < b.N; i++ {
replacer.Replace(context.TODO(), state, nil, "{type} {name} {size}")
}
}
@ -87,46 +117,74 @@ func (m *testHandler) ServeDNS(ctx context.Context, w dns.ResponseWriter, r *dns
}
func TestMetadataReplacement(t *testing.T) {
mdata := testProvider{
"test/key2": func() string { return "two" },
}
tests := []struct {
expr string
result string
}{
{"{name}", "example.org."},
{"{/test/key2}", "two"},
{"TYPE={type}, NAME={name}, BUFSIZE={>bufsize}, WHAT={/test/key2} .. and more", "TYPE=HINFO, NAME=example.org., BUFSIZE=512, WHAT=two .. and more"},
{"{/test/key2}{/test/key4}", "two-"},
{"{test/key2", "{test/key2"}, // if last } is missing, the end of format is considered static text
{"{/test-key2}", "-"}, // everything that is not a placeholder for log or a metadata label is invalid
{"{/test/meta2}", "two"},
{"{/test/meta2} {/test/key4}", "two -"},
{"{/test/meta2} {/test/meta3}", "two three"},
}
next := &testHandler{} // fake handler which stores the resulting context
next := &testHandler{}
m := metadata.Metadata{
Zones: []string{"."},
Providers: []metadata.Provider{mdata},
Next: next,
Zones: []string{"."},
Providers: []metadata.Provider{
testProvider{"test/meta2": func() string { return "two" }},
testProvider{"test/meta3": func() string { return "three" }},
},
Next: next,
}
ctx := context.TODO()
m.ServeDNS(ctx, &test.ResponseWriter{}, new(dns.Msg))
nctx := next.ctx
m.ServeDNS(context.TODO(), &test.ResponseWriter{}, new(dns.Msg))
ctx := next.ctx // important because the m.ServeDNS has only now populated the context
w := dnstest.NewRecorder(&test.ResponseWriter{})
r := new(dns.Msg)
r.SetQuestion("example.org.", dns.TypeHINFO)
r.MsgHdr.AuthenticatedData = true
repl := New(nctx, r, w, "-")
repl := New()
state := request.Request{W: w, Req: r}
for i, ts := range tests {
r := repl.Replace(ts.expr)
r := repl.Replace(ctx, state, nil, ts.expr)
if r != ts.result {
t.Errorf("Test %d - expr : %s, expected replacement being %s, and got %s", i, ts.expr, ts.result, r)
t.Errorf("Test %d - expr : %s, expected %q, got %q", i, ts.expr, ts.result, r)
}
}
}
func TestMetadataMalformed(t *testing.T) {
tests := []struct {
expr string
result string
}{
{"{/test/meta2", "{/test/meta2"},
{"{test/meta2} {/test/meta4}", "{test/meta2} -"},
{"{test}", "{test}"},
}
next := &testHandler{}
m := metadata.Metadata{
Zones: []string{"."},
Providers: []metadata.Provider{testProvider{"test/meta2": func() string { return "two" }}},
Next: next,
}
m.ServeDNS(context.TODO(), &test.ResponseWriter{}, new(dns.Msg))
ctx := next.ctx // important because the m.ServeDNS has only now populated the context
w := dnstest.NewRecorder(&test.ResponseWriter{})
r := new(dns.Msg)
r.SetQuestion("example.org.", dns.TypeHINFO)
repl := New()
state := request.Request{W: w, Req: r}
for i, ts := range tests {
r := repl.Replace(ctx, state, nil, ts.expr)
if r != ts.result {
t.Errorf("Test %d - expr : %s, expected %q, got %q", i, ts.expr, ts.result, r)
}
}
}

10
plugin/rewrite/condition.go
View file

@ -7,6 +7,7 @@ import (
"strings"
"github.com/coredns/coredns/plugin/pkg/replacer"
"github.com/coredns/coredns/request"
"github.com/miekg/dns"
)
@ -23,7 +24,7 @@ const (
NotMatch = "not_match"
)
func newReplacer(r *dns.Msg) replacer.Replacer { return replacer.New(context.TODO(), r, nil, "") }
var repl = replacer.New()
// condition is a rewrite condition.
type condition func(string, string) bool
@ -87,9 +88,10 @@ func (i If) True(r *dns.Msg) bool {
if c, ok := conditions[i.Operator]; ok {
a, b := i.A, i.B
if r != nil {
replacer := newReplacer(r)
a = replacer.Replace(i.A)
b = replacer.Replace(i.B)
ctx := context.TODO()
state := request.Request{Req: r, W: nil} // hmm W nil?
a = repl.Replace(ctx, state, nil, i.A)
b = repl.Replace(ctx, state, nil, i.B)
}
return c(a, b)
}