From 70b51a73d3a0029394dbdbc9f52a4d3d8e89d6f5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ond=C5=99ej=20Benkovsk=C3=BD?= Date: Fri, 9 Jul 2021 16:23:02 +0200 Subject: [PATCH] add configurable log level to errors plugin (#4718) Automatically submitted. --- plugin/errors/README.md | 8 ++--- plugin/errors/errors.go | 11 +++--- plugin/errors/errors_test.go | 63 +++++++++++++++++++++++++++------- plugin/errors/setup.go | 27 +++++++++++++-- plugin/errors/setup_test.go | 66 ++++++++++++++++++++++++++++++++++++ 5 files changed, 151 insertions(+), 24 deletions(-) diff --git a/plugin/errors/README.md b/plugin/errors/README.md index 61ed582cb..4a8ff3ce8 100644 --- a/plugin/errors/README.md +++ b/plugin/errors/README.md @@ -22,12 +22,12 @@ Extra knobs are available with an expanded syntax: ~~~ errors { - consolidate DURATION REGEXP + consolidate DURATION REGEXP [LEVEL] } ~~~ -Option `consolidate` allows collecting several error messages matching the regular expression **REGEXP** during **DURATION**. After the **DURATION** since receiving the first such message, the consolidated message will be printed to standard output, e.g. - +Option `consolidate` allows collecting several error messages matching the regular expression **REGEXP** during **DURATION**. After the **DURATION** since receiving the first such message, the consolidated message will be printed to standard output with +log level, which is configurable by optional option **LEVEL**. Supported options for **LEVEL** option are `warn`,`error`,`info` and `debug`. ~~~ 2 errors like '^read udp .* i/o timeout$' occurred in last 30s ~~~ @@ -53,7 +53,7 @@ Use the *forward* to resolve queries via 8.8.8.8 and print consolidated error me . { forward . 8.8.8.8 errors { - consolidate 5m ".* i/o timeout$" + consolidate 5m ".* i/o timeout$" warn consolidate 30s "^Failed to .+" } } diff --git a/plugin/errors/errors.go b/plugin/errors/errors.go index 9565f11ab..c045f6992 100644 --- a/plugin/errors/errors.go +++ b/plugin/errors/errors.go @@ -18,10 +18,11 @@ import ( var log = clog.NewWithPlugin("errors") type pattern struct { - ptimer unsafe.Pointer - count uint32 - period time.Duration - pattern *regexp.Regexp + ptimer unsafe.Pointer + count uint32 + period time.Duration + pattern *regexp.Regexp + logCallback func(format string, v ...interface{}) } func (p *pattern) timer() *time.Timer { @@ -46,7 +47,7 @@ func newErrorHandler() *errorHandler { func (h *errorHandler) logPattern(i int) { cnt := atomic.SwapUint32(&h.patterns[i].count, 0) if cnt > 0 { - log.Errorf("%d errors like '%s' occurred in last %s", + h.patterns[i].logCallback("%d errors like '%s' occurred in last %s", cnt, h.patterns[i].pattern.String(), h.patterns[i].period) } } diff --git a/plugin/errors/errors_test.go b/plugin/errors/errors_test.go index 9563b7323..ba9a9b571 100644 --- a/plugin/errors/errors_test.go +++ b/plugin/errors/errors_test.go @@ -14,6 +14,7 @@ import ( "github.com/coredns/coredns/plugin" "github.com/coredns/coredns/plugin/pkg/dnstest" + clog "github.com/coredns/coredns/plugin/pkg/log" "github.com/coredns/coredns/plugin/test" "github.com/miekg/dns" @@ -71,21 +72,56 @@ func TestErrors(t *testing.T) { } func TestLogPattern(t *testing.T) { - buf := bytes.Buffer{} - golog.SetOutput(&buf) - - h := &errorHandler{ - patterns: []*pattern{{ - count: 4, - period: 2 * time.Second, - pattern: regexp.MustCompile("^error.*!$"), - }}, + type args struct { + logCallback func(format string, v ...interface{}) + } + tests := []struct { + name string + args args + want string + }{ + { + name: "error log", + args: args{logCallback: log.Errorf}, + want: "[ERROR] plugin/errors: 4 errors like '^error.*!$' occurred in last 2s", + }, + { + name: "warn log", + args: args{logCallback: log.Warningf}, + want: "[WARNING] plugin/errors: 4 errors like '^error.*!$' occurred in last 2s", + }, + { + name: "info log", + args: args{logCallback: log.Infof}, + want: "[INFO] plugin/errors: 4 errors like '^error.*!$' occurred in last 2s", + }, + { + name: "debug log", + args: args{logCallback: log.Debugf}, + want: "[DEBUG] plugin/errors: 4 errors like '^error.*!$' occurred in last 2s", + }, } - h.logPattern(0) - expLog := "4 errors like '^error.*!$' occurred in last 2s" - if log := buf.String(); !strings.Contains(log, expLog) { - t.Errorf("Expected log %q, but got %q", expLog, log) + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + buf := bytes.Buffer{} + clog.D.Set() + golog.SetOutput(&buf) + + h := &errorHandler{ + patterns: []*pattern{{ + count: 4, + period: 2 * time.Second, + pattern: regexp.MustCompile("^error.*!$"), + logCallback: tt.args.logCallback, + }}, + } + h.logPattern(0) + + if log := buf.String(); !strings.Contains(log, tt.want) { + t.Errorf("Expected log %q, but got %q", tt.want, log) + } + }) } } @@ -154,6 +190,7 @@ func TestStop(t *testing.T) { patterns: []*pattern{{ period: 2 * time.Second, pattern: regexp.MustCompile("^error.*!$"), + logCallback: log.Errorf, }}, } diff --git a/plugin/errors/setup.go b/plugin/errors/setup.go index ef279dadf..9fc5a3595 100644 --- a/plugin/errors/setup.go +++ b/plugin/errors/setup.go @@ -66,7 +66,7 @@ func parseBlock(c *caddy.Controller, h *errorHandler) error { } args := c.RemainingArgs() - if len(args) != 2 { + if len(args) < 2 || len(args) > 3 { return c.ArgErr() } p, err := time.ParseDuration(args[0]) @@ -77,7 +77,30 @@ func parseBlock(c *caddy.Controller, h *errorHandler) error { if err != nil { return c.Err(err.Error()) } - h.patterns = append(h.patterns, &pattern{period: p, pattern: re}) + lc, err := parseLogLevel(c, args) + if err != nil { + return err + } + h.patterns = append(h.patterns, &pattern{period: p, pattern: re, logCallback: lc}) return nil } + +func parseLogLevel(c *caddy.Controller, args []string) (func(format string, v ...interface{}), error) { + if len(args) != 3 { + return log.Errorf, nil + } + + switch args[2] { + case "warn": + return log.Warningf, nil + case "error": + return log.Errorf, nil + case "info": + return log.Infof, nil + case "debug": + return log.Debugf, nil + default: + return nil, c.Err("unknown log level argument in consolidate") + } +} diff --git a/plugin/errors/setup_test.go b/plugin/errors/setup_test.go index c61cf54c4..3bfb87c8d 100644 --- a/plugin/errors/setup_test.go +++ b/plugin/errors/setup_test.go @@ -1,9 +1,13 @@ package errors import ( + "bytes" + golog "log" + "strings" "testing" "github.com/coredns/caddy" + clog "github.com/coredns/coredns/plugin/pkg/log" ) func TestErrorsParse(t *testing.T) { @@ -67,3 +71,65 @@ func TestErrorsParse(t *testing.T) { } } } + +func TestProperLogCallbackIsSet(t *testing.T) { + tests := []struct { + name string + inputErrorsRules string + wantLogLevel string + }{ + { + name: "warn is parsed properly", + inputErrorsRules: `errors { + consolidate 1m .* warn + }`, + wantLogLevel: "[WARNING]", + }, + { + name: "error is parsed properly", + inputErrorsRules: `errors { + consolidate 1m .* error + }`, + wantLogLevel: "[ERROR]", + }, + { + name: "info is parsed properly", + inputErrorsRules: `errors { + consolidate 1m .* info + }`, + wantLogLevel: "[INFO]", + }, + { + name: "debug is parsed properly", + inputErrorsRules: `errors { + consolidate 1m .* debug + }`, + wantLogLevel: "[DEBUG]", + }, + { + name: "default is error", + inputErrorsRules: `errors { + consolidate 1m .* + }`, + wantLogLevel: "[ERROR]", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + buf := bytes.Buffer{} + golog.SetOutput(&buf) + clog.D.Set() + + c := caddy.NewTestController("dns", tt.inputErrorsRules) + h, _ := errorsParse(c) + + l := h.patterns[0].logCallback + l("some error happened") + + if log := buf.String(); !strings.Contains(log, tt.wantLogLevel) { + t.Errorf("Expected log %q, but got %q", tt.wantLogLevel, log) + } + }) + } +}