From a8b92d1c81436105e740b4cc69de6fcbd56b2c7b Mon Sep 17 00:00:00 2001
From: Sumner Evans <sumner@beeper.com>
Date: Mon, 26 Jun 2023 16:08:12 -0600
Subject: [PATCH] logging: don't log request start, just log end

Signed-off-by: Sumner Evans <sumner@beeper.com>
---
 client.go | 26 +++++++++++---------------
 1 file changed, 11 insertions(+), 15 deletions(-)

diff --git a/client.go b/client.go
index ad9b2549..66cba144 100644
--- a/client.go
+++ b/client.go
@@ -14,7 +14,6 @@ import (
 	"net/url"
 	"os"
 	"strconv"
-	"strings"
 	"sync/atomic"
 	"time"
 
@@ -258,18 +257,10 @@ const (
 	LogRequestIDContextKey
 )
 
-func (cli *Client) LogRequest(req *http.Request) {
+func (cli *Client) RequestStart(req *http.Request) {
 	if cli.RequestHook != nil {
 		cli.RequestHook(req)
 	}
-	evt := zerolog.Ctx(req.Context()).Debug().
-		Str("method", req.Method).
-		Str("url", req.URL.String())
-	body := req.Context().Value(LogBodyContextKey)
-	if body != nil {
-		evt.Interface("body", body)
-	}
-	evt.Msg("Sending request")
 }
 
 func (cli *Client) LogRequestDone(req *http.Request, resp *http.Response, handlerErr error, contentLength int, duration time.Duration) {
@@ -281,15 +272,16 @@ func (cli *Client) LogRequestDone(req *http.Request, resp *http.Response, handle
 	if length == -1 && contentLength > 0 {
 		length = int64(contentLength)
 	}
-	path := strings.TrimPrefix(req.URL.Path, cli.HomeserverURL.Path)
-	path = strings.TrimPrefix(path, "/_matrix/client")
 	evt := zerolog.Ctx(req.Context()).Debug().
 		Str("method", req.Method).
-		Str("path", path).
+		Str("url", req.URL.String()).
 		Int("status_code", resp.StatusCode).
 		Int64("response_length", length).
 		Str("response_mime", mime).
 		Dur("duration", duration)
+	if body := req.Context().Value(LogBodyContextKey); body != nil {
+		evt.Interface("body", body)
+	}
 	if handlerErr != nil {
 		evt.AnErr("body_parse_err", handlerErr)
 	}
@@ -551,7 +543,7 @@ func (cli *Client) shouldRetry(res *http.Response) bool {
 }
 
 func (cli *Client) executeCompiledRequest(req *http.Request, retries int, backoff time.Duration, responseJSON interface{}, handler ClientResponseHandler) ([]byte, error) {
-	cli.LogRequest(req)
+	cli.RequestStart(req)
 	startTime := time.Now()
 	res, err := cli.Client.Do(req)
 	duration := time.Now().Sub(startTime)
@@ -1388,14 +1380,18 @@ func (cli *Client) downloadContext(ctx context.Context, mxcURL id.ContentURI) (*
 		return nil, err
 	}
 	req.Header.Set("User-Agent", cli.UserAgent+" (media downloader)")
-	cli.LogRequest(req)
+	cli.RequestStart(req)
+	downloadStart := time.Now()
 	if resp, err := cli.Client.Do(req); err != nil {
+		cli.LogRequestDone(req, resp, err, 0, time.Since(downloadStart))
 		return nil, err
 	} else if resp.StatusCode < 200 || resp.StatusCode >= 300 {
 		_, err = ParseErrorResponse(req, resp)
 		_ = resp.Body.Close()
+		cli.LogRequestDone(req, resp, err, 0, time.Since(downloadStart))
 		return nil, err
 	} else {
+		cli.LogRequestDone(req, resp, err, -1, time.Since(downloadStart))
 		return resp, nil
 	}
 }