From: Ivan Babrou <ibobrik@gmail.com>
Date: Thu, 4 Oct 2018 10:59:29 +0000 (-0700)
Subject: Account response read time for http prober (#363)
X-Git-Url: https://vcs.fsf.org/?a=commitdiff_plain;h=5cbb0848265b369c3ce8b9fa0dcb032c5718af7c;p=blackbox_exporter.git

Account response read time for http prober (#363)

Withot this change `transfer` time is near zero, because `trace.end`
time is clocked when response body is available, not when it's read.

Signed-off-by: Ivan Babrou <ibobrik@gmail.com>
---

diff --git a/prober/http.go b/prober/http.go
index bbc4543..71d1dec 100644
--- a/prober/http.go
+++ b/prober/http.go
@@ -104,7 +104,6 @@ func (t *transport) RoundTrip(req *http.Request) (*http.Response, error) {
 	}
 	t.current = trace
 	t.traces = append(t.traces, trace)
-	defer func() { trace.end = time.Now() }()
 	return t.Transport.RoundTrip(req)
 }
 
@@ -296,10 +295,8 @@ func ProbeHTTP(ctx context.Context, target string, module config.Module, registr
 	if err != nil && resp == nil {
 		level.Error(logger).Log("msg", "Error for HTTP request", "err", err)
 	} else {
-		defer func() {
-			io.Copy(ioutil.Discard, resp.Body)
-			resp.Body.Close()
-		}()
+		requestErrored := (err != nil)
+
 		level.Info(logger).Log("msg", "Received HTTP response", "status_code", resp.StatusCode)
 		if len(httpConfig.ValidStatusCodes) != 0 {
 			for _, code := range httpConfig.ValidStatusCodes {
@@ -327,6 +324,19 @@ func ProbeHTTP(ctx context.Context, target string, module config.Module, registr
 			}
 		}
 
+		if resp != nil && !requestErrored {
+			_, err = io.Copy(ioutil.Discard, resp.Body)
+			if err != nil {
+				level.Info(logger).Log("msg", "Failed to read HTTP response body", "err", err)
+				success = false
+			}
+
+			resp.Body.Close()
+		}
+
+		// At this point body is fully read and we can write end time.
+		tt.current.end = time.Now()
+
 		var httpVersionNumber float64
 		httpVersionNumber, err = strconv.ParseFloat(strings.TrimPrefix(resp.Proto, "HTTP/"), 64)
 		if err != nil {
@@ -385,6 +395,12 @@ func ProbeHTTP(ctx context.Context, target string, module config.Module, registr
 			continue
 		}
 		durationGaugeVec.WithLabelValues("processing").Add(trace.responseStart.Sub(trace.gotConn).Seconds())
+
+		// Continue here if we never read the full response from the server.
+		// Usually this means that request either failed or was redirected.
+		if trace.end.IsZero() {
+			continue
+		}
 		durationGaugeVec.WithLabelValues("transfer").Add(trace.end.Sub(trace.responseStart).Seconds())
 	}