Log errors from probe (#1091)

* Log errors from probe Signed-off-by: Jan-Otto Kröpke <mail@jkroepke.de> * Update main.go Co-authored-by: Ben Kochie <superq@gmail.com> Signed-off-by: Jan-Otto Kröpke <github@jkroepke.de> * Implement --log.prober Signed-off-by: Jan-Otto Kröpke <mail@jkroepke.de> --------- Signed-off-by: Jan-Otto Kröpke <mail@jkroepke.de> Signed-off-by: Jan-Otto Kröpke <github@jkroepke.de> Co-authored-by: Ben Kochie <superq@gmail.com>
prometheus · Jul 22, 2023 · c908cba · c908cba
1 parent 52e9144
commit c908cba
Show file tree

Hide file tree

Showing 4 changed files with 30 additions and 29 deletions.
diff --git 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("<url>").String()
-	routePrefix   = kingpin.Flag("web.route-prefix", "Prefix for the internal routes of web endpoints. Defaults to path of --web.external-url.").PlaceHolder("<path>").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("<url>").String()
+	routePrefix    = kingpin.Flag("web.route-prefix", "Prefix for the internal routes of web endpoints. Defaults to path of --web.external-url.").PlaceHolder("<path>").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
@@ -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
@@ -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
@@ -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)