From 2bf957e6dd7e1aa816bab30fce92547542da8dae Mon Sep 17 00:00:00 2001 From: Adrian Serrano Date: Mon, 5 Jun 2023 14:36:24 +0200 Subject: [PATCH] http: Prevent logging confusing error message (#1059) * http: Prevent logging confusing error message When FailIfNotSSL is set, the error message: > Final request was not over SSL is logged even if a previous error has prevented the request to complete, for example when it fails due to a timeout or connection error. This updates the logic around the log message so it's printed when an otherwise successful request is not performed over SSL and that causes the probe to fail. Signed-off-by: Adrian Serrano * Add a test to validate log message Signed-off-by: Adrian Serrano --------- Signed-off-by: Adrian Serrano --- prober/http.go | 2 +- prober/http_test.go | 90 +++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 91 insertions(+), 1 deletion(-) diff --git a/prober/http.go b/prober/http.go index 441edc47..232214c3 100644 --- a/prober/http.go +++ b/prober/http.go @@ -647,7 +647,7 @@ func ProbeHTTP(ctx context.Context, target string, module config.Module, registr level.Error(logger).Log("msg", "Final request was over SSL") success = false } - } else if httpConfig.FailIfNotSSL { + } else if httpConfig.FailIfNotSSL && success { level.Error(logger).Log("msg", "Final request was not over SSL") success = false } diff --git a/prober/http_test.go b/prober/http_test.go index 3d7dfdb2..05ca36d8 100644 --- a/prober/http_test.go +++ b/prober/http_test.go @@ -23,6 +23,7 @@ import ( "encoding/pem" "fmt" "io" + "net" "net/http" "net/http/httptest" "net/textproto" @@ -836,6 +837,95 @@ func TestFailIfNotSSL(t *testing.T) { checkRegistryResults(expectedResults, mfs, t) } +type logRecorder struct { + msgs map[string]bool +} + +func (r *logRecorder) Log(keyvals ...interface{}) error { + if r.msgs == nil { + r.msgs = make(map[string]bool) + } + for i := 0; i < len(keyvals)-1; i += 2 { + if keyvals[i] == "msg" { + msg, ok := keyvals[i+1].(string) + if ok { + r.msgs[msg] = true + } + } + } + return nil +} + +func TestFailIfNotSSLLogMsg(t *testing.T) { + const ( + Msg = "Final request was not over SSL" + Timeout = time.Second * 10 + ) + + goodServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + })) + defer goodServer.Close() + + // Create a TCP server that closes the connection without an answer, to simulate failure. + listener, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + defer listener.Close() + go func() { + for { + conn, err := listener.Accept() + if err != nil { + return + } + conn.Close() + } + }() + badServerURL := fmt.Sprintf("http://%s/", listener.Addr().String()) + + for title, tc := range map[string]struct { + Config config.Module + URL string + Success bool + MessageExpected bool + }{ + "SSL expected, message": { + Config: config.Module{HTTP: config.HTTPProbe{IPProtocolFallback: true, FailIfNotSSL: true}}, + URL: goodServer.URL, + Success: false, + MessageExpected: true, + }, + "No SSL expected, no message": { + Config: config.Module{HTTP: config.HTTPProbe{IPProtocolFallback: true, FailIfNotSSL: false}}, + URL: goodServer.URL, + Success: true, + MessageExpected: false, + }, + "SSL expected, no message": { + Config: config.Module{HTTP: config.HTTPProbe{IPProtocolFallback: true, FailIfNotSSL: true}}, + URL: badServerURL, + Success: false, + MessageExpected: false, + }, + } { + t.Run(title, func(t *testing.T) { + recorder := logRecorder{} + registry := prometheus.NewRegistry() + testCTX, cancel := context.WithTimeout(context.Background(), Timeout) + defer cancel() + + result := ProbeHTTP(testCTX, tc.URL, tc.Config, registry, &recorder) + if result != tc.Success { + t.Fatalf("Expected success=%v, got=%v", tc.Success, result) + } + if seen := recorder.msgs[Msg]; seen != tc.MessageExpected { + t.Fatalf("SSL message expected=%v, seen=%v", tc.MessageExpected, seen) + } + }) + } +} + func TestFailIfBodyMatchesRegexp(t *testing.T) { testcases := map[string]struct { respBody string