client/logging: log HTTP errors separate from handler errors

Signed-off-by: Sumner Evans <sumner@beeper.com>

client.go

@@ -263,8 +263,17 @@ func (cli *Client) RequestStart(req *http.Request) {
 	}
 }
 
-func (cli *Client) LogRequestDone(req *http.Request, resp *http.Response, handlerErr error, contentLength int, duration time.Duration) {
-	evt := zerolog.Ctx(req.Context()).Debug().
+func (cli *Client) LogRequestDone(req *http.Request, resp *http.Response, err error, handlerErr error, contentLength int, duration time.Duration) {
+	var evt *zerolog.Event
+	if err != nil {
+		evt = zerolog.Ctx(req.Context()).Err(err)
+	} else if handlerErr != nil {
+		evt = zerolog.Ctx(req.Context()).Warn().
+			AnErr("body_parse_err", handlerErr)
+	} else {
+		evt = zerolog.Ctx(req.Context()).Debug()
+	}
+	evt = evt.
 		Str("method", req.Method).
 		Str("url", req.URL.String()).
 		Dur("duration", duration)
@@ -287,10 +296,13 @@ func (cli *Client) LogRequestDone(req *http.Request, resp *http.Response, handle
 	if body := req.Context().Value(LogBodyContextKey); body != nil {
 		evt.Interface("req_body", body)
 	}
-	if handlerErr != nil {
-		evt.AnErr("body_parse_err", handlerErr)
+	if err != nil {
+		evt.Msg("Request failed")
+	} else if handlerErr != nil {
+		evt.Msg("Request parsing failed")
+	} else {
+		evt.Msg("Request completed")
 	}
-	evt.Msg("Request completed")
 }
 
 func (cli *Client) MakeRequest(method string, httpURL string, reqBody interface{}, resBody interface{}) ([]byte, error) {
@@ -556,13 +568,15 @@ func (cli *Client) executeCompiledRequest(req *http.Request, retries int, backof
 		if retries > 0 {
 			return cli.doRetry(req, err, retries, backoff, responseJSON, handler)
 		}
-		return nil, HTTPError{
+		err = HTTPError{
 			Request:  req,
 			Response: res,
 
 			Message:      "request error",
 			WrappedError: err,
 		}
+		cli.LogRequestDone(req, res, err, nil, 0, duration)
+		return nil, err
 	}
 
 	if retries > 0 && cli.shouldRetry(res) {
@@ -575,10 +589,10 @@ func (cli *Client) executeCompiledRequest(req *http.Request, retries int, backof
 	var body []byte
 	if res.StatusCode < 200 || res.StatusCode >= 300 {
 		body, err = ParseErrorResponse(req, res)
-		cli.LogRequestDone(req, res, nil, len(body), duration)
+		cli.LogRequestDone(req, res, err, nil, len(body), duration)
 	} else {
 		body, err = handler(req, res, responseJSON)
-		cli.LogRequestDone(req, res, err, len(body), duration)
+		cli.LogRequestDone(req, res, nil, err, len(body), duration)
 	}
 	return body, err
 }
@@ -1385,15 +1399,15 @@ func (cli *Client) downloadContext(ctx context.Context, mxcURL id.ContentURI) (*
 	cli.RequestStart(req)
 	downloadStart := time.Now()
 	if resp, err := cli.Client.Do(req); err != nil {
-		cli.LogRequestDone(req, resp, err, 0, time.Since(downloadStart))
+		cli.LogRequestDone(req, resp, err, nil, 0, time.Since(downloadStart))
 		return nil, err
 	} else if resp.StatusCode < 200 || resp.StatusCode >= 300 {
-		_, err = ParseErrorResponse(req, resp)
+		body, err := ParseErrorResponse(req, resp)
 		_ = resp.Body.Close()
-		cli.LogRequestDone(req, resp, err, 0, time.Since(downloadStart))
+		cli.LogRequestDone(req, resp, err, nil, len(body), time.Since(downloadStart))
 		return nil, err
 	} else {
-		cli.LogRequestDone(req, resp, err, -1, time.Since(downloadStart))
+		cli.LogRequestDone(req, resp, nil, nil, -1, time.Since(downloadStart))
 		return resp, nil
 	}
 }