From 5cbb0848265b369c3ce8b9fa0dcb032c5718af7c Mon Sep 17 00:00:00 2001 From: Ivan Babrou Date: Thu, 4 Oct 2018 03:59:29 -0700 Subject: [PATCH] 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 --- prober/http.go | 26 +++++++++++++++++++++----- 1 file changed, 21 insertions(+), 5 deletions(-) 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()) } -- 2.25.1