From c908cba63b5256af83d0553e7fb5049f709aaeac Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan-Otto=20Kr=C3=B6pke?= Date: Sat, 22 Jul 2023 18:40:02 +0200 Subject: [PATCH] Log errors from probe (#1091) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * Log errors from probe Signed-off-by: Jan-Otto Kröpke * Update main.go Co-authored-by: Ben Kochie Signed-off-by: Jan-Otto Kröpke * Implement --log.prober Signed-off-by: Jan-Otto Kröpke --------- Signed-off-by: Jan-Otto Kröpke Signed-off-by: Jan-Otto Kröpke Co-authored-by: Ben Kochie --- main.go | 20 ++++++++++++-------- prober/handler.go | 26 +++++++++++--------------- prober/handler_test.go | 11 ++++++----- prober/icmp.go | 2 +- 4 files changed, 30 insertions(+), 29 deletions(-) diff --git a/main.go b/main.go index 2699b6f8..0d113b4b 100644 --- a/main.go +++ b/main.go @@ -47,13 +47,14 @@ import ( var ( sc = config.NewSafeConfig(prometheus.DefaultRegisterer) - configFile = kingpin.Flag("config.file", "Blackbox exporter configuration file.").Default("blackbox.yml").String() - timeoutOffset = kingpin.Flag("timeout-offset", "Offset to subtract from timeout in seconds.").Default("0.5").Float64() - configCheck = kingpin.Flag("config.check", "If true validate the config file and then exit.").Default().Bool() - historyLimit = kingpin.Flag("history.limit", "The maximum amount of items to keep in the history.").Default("100").Uint() - externalURL = kingpin.Flag("web.external-url", "The URL under which Blackbox exporter is externally reachable (for example, if Blackbox exporter is served via a reverse proxy). Used for generating relative and absolute links back to Blackbox exporter itself. If the URL has a path portion, it will be used to prefix all HTTP endpoints served by Blackbox exporter. If omitted, relevant URL components will be derived automatically.").PlaceHolder("").String() - routePrefix = kingpin.Flag("web.route-prefix", "Prefix for the internal routes of web endpoints. Defaults to path of --web.external-url.").PlaceHolder("").String() - toolkitFlags = webflag.AddFlags(kingpin.CommandLine, ":9115") + configFile = kingpin.Flag("config.file", "Blackbox exporter configuration file.").Default("blackbox.yml").String() + timeoutOffset = kingpin.Flag("timeout-offset", "Offset to subtract from timeout in seconds.").Default("0.5").Float64() + configCheck = kingpin.Flag("config.check", "If true validate the config file and then exit.").Default().Bool() + logLevelProber = kingpin.Flag("log.prober", "Log level from probe requests. One of: [debug, info, warn, error, none]").Default("none").String() + historyLimit = kingpin.Flag("history.limit", "The maximum amount of items to keep in the history.").Default("100").Uint() + externalURL = kingpin.Flag("web.external-url", "The URL under which Blackbox exporter is externally reachable (for example, if Blackbox exporter is served via a reverse proxy). Used for generating relative and absolute links back to Blackbox exporter itself. If the URL has a path portion, it will be used to prefix all HTTP endpoints served by Blackbox exporter. If omitted, relevant URL components will be derived automatically.").PlaceHolder("").String() + routePrefix = kingpin.Flag("web.route-prefix", "Prefix for the internal routes of web endpoints. Defaults to path of --web.external-url.").PlaceHolder("").String() + toolkitFlags = webflag.AddFlags(kingpin.CommandLine, ":9115") moduleUnknownCounter = promauto.NewCounter(prometheus.CounterOpts{ Name: "blackbox_module_unknown_total", @@ -79,6 +80,9 @@ func run() int { logger := promlog.New(promlogConfig) rh := &prober.ResultHistory{MaxResults: *historyLimit} + logLevelProberValue, _ := level.Parse(*logLevelProber) + logLevelProber := level.Allow(logLevelProberValue) + level.Info(logger).Log("msg", "Starting blackbox_exporter", "version", version.Info()) level.Info(logger).Log("build_context", version.BuildContext()) @@ -182,7 +186,7 @@ func run() int { sc.Lock() conf := sc.C sc.Unlock() - prober.Handler(w, r, conf, logger, rh, *timeoutOffset, nil, moduleUnknownCounter) + prober.Handler(w, r, conf, logger, rh, *timeoutOffset, nil, moduleUnknownCounter, logLevelProber) }) http.HandleFunc(*routePrefix, func(w http.ResponseWriter, r *http.Request) { w.Header().Set("Content-Type", "text/html") diff --git a/prober/handler.go b/prober/handler.go index 1caa2f92..180a076b 100644 --- a/prober/handler.go +++ b/prober/handler.go @@ -42,8 +42,9 @@ var ( } ) -func Handler(w http.ResponseWriter, r *http.Request, c *config.Config, logger log.Logger, - rh *ResultHistory, timeoutOffset float64, params url.Values, moduleUnknownCounter prometheus.Counter) { +func Handler(w http.ResponseWriter, r *http.Request, c *config.Config, logger log.Logger, rh *ResultHistory, timeoutOffset float64, params url.Values, + moduleUnknownCounter prometheus.Counter, + logLevelProber level.Option) { if params == nil { params = r.URL.Query() @@ -108,7 +109,7 @@ func Handler(w http.ResponseWriter, r *http.Request, c *config.Config, logger lo } } - sl := newScrapeLogger(logger, moduleName, target) + sl := newScrapeLogger(logger, moduleName, target, logLevelProber) level.Info(sl).Log("msg", "Beginning probe", "probe", module.Prober, "timeout_seconds", timeoutSeconds) start := time.Now() @@ -159,13 +160,15 @@ type scrapeLogger struct { next log.Logger buffer bytes.Buffer bufferLogger log.Logger + logLevel level.Option } -func newScrapeLogger(logger log.Logger, module string, target string) *scrapeLogger { +func newScrapeLogger(logger log.Logger, module string, target string, logLevel level.Option) *scrapeLogger { logger = log.With(logger, "module", module, "target", target) sl := &scrapeLogger{ - next: logger, - buffer: bytes.Buffer{}, + next: logger, + buffer: bytes.Buffer{}, + logLevel: logLevel, } bl := log.NewLogfmtLogger(&sl.buffer) sl.bufferLogger = log.With(bl, "ts", log.DefaultTimestampUTC, "caller", log.Caller(6), "module", module, "target", target) @@ -174,15 +177,8 @@ func newScrapeLogger(logger log.Logger, module string, target string) *scrapeLog func (sl scrapeLogger) Log(keyvals ...interface{}) error { sl.bufferLogger.Log(keyvals...) - kvs := make([]interface{}, len(keyvals)) - copy(kvs, keyvals) - // Switch level to debug for application output. - for i := 0; i < len(kvs); i += 2 { - if kvs[i] == level.Key() { - kvs[i+1] = level.DebugValue() - } - } - return sl.next.Log(kvs...) + + return level.NewFilter(sl.next, sl.logLevel).Log(keyvals...) } // DebugOutput returns plaintext debug output for a probe. diff --git a/prober/handler_test.go b/prober/handler_test.go index 885f751d..e9897ab3 100644 --- a/prober/handler_test.go +++ b/prober/handler_test.go @@ -25,6 +25,7 @@ import ( "time" "github.com/go-kit/log" + "github.com/go-kit/log/level" "github.com/prometheus/client_golang/prometheus" pconfig "github.com/prometheus/common/config" @@ -59,7 +60,7 @@ func TestPrometheusTimeoutHTTP(t *testing.T) { rr := httptest.NewRecorder() handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil) + Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil, level.AllowNone()) }) handler.ServeHTTP(rr, req) @@ -81,7 +82,7 @@ func TestPrometheusConfigSecretsHidden(t *testing.T) { } rr := httptest.NewRecorder() handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil) + Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil, level.AllowNone()) }) handler.ServeHTTP(rr, req) @@ -177,7 +178,7 @@ func TestHostnameParam(t *testing.T) { rr := httptest.NewRecorder() handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil) + Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil, level.AllowNone()) }) handler.ServeHTTP(rr, req) @@ -195,7 +196,7 @@ func TestHostnameParam(t *testing.T) { c.Modules["http_2xx"].HTTP.Headers["Host"] = hostname + ".something" handler = http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil) + Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil, level.AllowNone()) }) rr = httptest.NewRecorder() @@ -242,7 +243,7 @@ func TestTCPHostnameParam(t *testing.T) { rr := httptest.NewRecorder() handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil) + Handler(w, r, c, log.NewNopLogger(), &ResultHistory{}, 0.5, nil, nil, level.AllowNone()) }) handler.ServeHTTP(rr, req) diff --git a/prober/icmp.go b/prober/icmp.go index 1f8432a9..f7807528 100644 --- a/prober/icmp.go +++ b/prober/icmp.go @@ -91,7 +91,7 @@ func ProbeICMP(ctx context.Context, target string, module config.Module, registr dstIPAddr, lookupTime, err := chooseProtocol(ctx, module.ICMP.IPProtocol, module.ICMP.IPProtocolFallback, target, registry, logger) if err != nil { - level.Warn(logger).Log("msg", "Error resolving address", "err", err) + level.Error(logger).Log("msg", "Error resolving address", "err", err) return false } durationGaugeVec.WithLabelValues("resolve").Add(lookupTime)