Account response read time for http prober (#363)
authorIvan Babrou <ibobrik@gmail.com>
Thu, 4 Oct 2018 10:59:29 +0000 (03:59 -0700)
committerBrian Brazil <brian.brazil@robustperception.io>
Thu, 4 Oct 2018 10:59:29 +0000 (11:59 +0100)
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>
prober/http.go

index bbc454340a03589bca4ee35293326ca27e28ca9f..71d1dec83f36a4664a6cf8d2843084d4efc0454b 100644 (file)
@@ -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())
        }