From 2b0156b1fc4f71d2f9a56bf7c1764333d91ed8f3 Mon Sep 17 00:00:00 2001 From: Anis Eleuch Date: Tue, 24 Sep 2024 18:12:18 +0100 Subject: [PATCH] Add TTFB to all APIs and enable for responses without body (#20479) Add TTFB for all requests in metrics-v3 in addition to the existing GetObject. Also for the requests that do not return a body in the response, calculate TTFB as the HTTP status code and the headers are sent. --- cmd/http-stats.go | 4 ++-- cmd/http-tracer.go | 2 +- cmd/metrics-v3-api.go | 4 ++-- internal/http/response-recorder.go | 20 ++++++++++++++++---- internal/logger/audit.go | 2 +- 5 files changed, 22 insertions(+), 10 deletions(-) diff --git a/cmd/http-stats.go b/cmd/http-stats.go index 077a72575..18a24e589 100644 --- a/cmd/http-stats.go +++ b/cmd/http-stats.go @@ -133,7 +133,7 @@ func (bh *bucketHTTPStats) updateHTTPStats(bucket, api string, w *xhttp.Response bucketHTTPRequestsDuration.With(prometheus.Labels{ "api": api, "bucket": bucket, - }).Observe(w.TimeToFirstByte.Seconds()) + }).Observe(w.TTFB().Seconds()) } bh.Lock() @@ -433,7 +433,7 @@ func (st *HTTPStats) updateStats(api string, w *xhttp.ResponseRecorder) { st.totalS3Requests.Inc(api) // Increment the prometheus http request response histogram with appropriate label - httpRequestsDuration.With(prometheus.Labels{"api": api}).Observe(w.TimeToFirstByte.Seconds()) + httpRequestsDuration.With(prometheus.Labels{"api": api}).Observe(w.TTFB().Seconds()) code := w.StatusCode diff --git a/cmd/http-tracer.go b/cmd/http-tracer.go index cbc2ce4ac..e7ad7462d 100644 --- a/cmd/http-tracer.go +++ b/cmd/http-tracer.go @@ -164,7 +164,7 @@ func httpTracerMiddleware(h http.Handler) http.Handler { Latency: reqEndTime.Sub(respRecorder.StartTime), InputBytes: inputBytes, OutputBytes: respRecorder.Size(), - TimeToFirstByte: respRecorder.TimeToFirstByte, + TimeToFirstByte: respRecorder.TTFB(), }, }, } diff --git a/cmd/metrics-v3-api.go b/cmd/metrics-v3-api.go index 2f35bb3ce..07265f037 100644 --- a/cmd/metrics-v3-api.go +++ b/cmd/metrics-v3-api.go @@ -129,7 +129,7 @@ func loadAPIRequestsHTTPMetrics(ctx context.Context, m MetricValues, _ *metricsC // This is a `MetricsLoaderFn`. func loadAPIRequestsTTFBMetrics(ctx context.Context, m MetricValues, _ *metricsCache) error { renameLabels := map[string]string{"api": "name"} - labelsFilter := map[string]set.StringSet{"api": set.CreateStringSet("GetObject")} + labelsFilter := map[string]set.StringSet{} m.SetHistogram(apiRequestsTTFBSecondsDistribution, httpRequestsDuration, labelsFilter, renameLabels, nil, "type", "s3") return nil @@ -217,7 +217,7 @@ func loadBucketAPIHTTPMetrics(ctx context.Context, m MetricValues, _ *metricsCac // This is a `MetricsLoaderFn`. func loadBucketAPITTFBMetrics(ctx context.Context, m MetricValues, _ *metricsCache, buckets []string) error { renameLabels := map[string]string{"api": "name"} - labelsFilter := map[string]set.StringSet{"api": set.CreateStringSet("GetObject")} + labelsFilter := map[string]set.StringSet{} m.SetHistogram(apiRequestsTTFBSecondsDistribution, bucketHTTPRequestsDuration, labelsFilter, renameLabels, buckets, "type", "s3") return nil diff --git a/internal/http/response-recorder.go b/internal/http/response-recorder.go index aeca35466..0777eac4f 100644 --- a/internal/http/response-recorder.go +++ b/internal/http/response-recorder.go @@ -41,8 +41,10 @@ type ResponseRecorder struct { // Log body of all responses LogAllBody bool - TimeToFirstByte time.Duration - StartTime time.Time + ttfbHeader time.Duration + ttfbBody time.Duration + + StartTime time.Time // number of bytes written bytesWritten int // number of bytes of response headers written @@ -63,6 +65,15 @@ func (lrw *ResponseRecorder) Hijack() (net.Conn, *bufio.ReadWriter, error) { return hj.Hijack() } +// TTFB of the request - this function needs to be called +// when the request is finished to provide accurate data +func (lrw *ResponseRecorder) TTFB() time.Duration { + if lrw.ttfbBody != 0 { + return lrw.ttfbBody + } + return lrw.ttfbHeader +} + // NewResponseRecorder - returns a wrapped response writer to trap // http status codes for auditing purposes. func NewResponseRecorder(w http.ResponseWriter) *ResponseRecorder { @@ -97,8 +108,8 @@ func (lrw *ResponseRecorder) Write(p []byte) (int, error) { } n, err := lrw.ResponseWriter.Write(p) lrw.bytesWritten += n - if lrw.TimeToFirstByte == 0 { - lrw.TimeToFirstByte = time.Now().UTC().Sub(lrw.StartTime) + if lrw.ttfbBody == 0 { + lrw.ttfbBody = time.Now().UTC().Sub(lrw.StartTime) } if (lrw.LogErrBody && lrw.StatusCode >= http.StatusBadRequest) || lrw.LogAllBody { @@ -159,6 +170,7 @@ func (lrw *ResponseRecorder) Body() []byte { // WriteHeader - writes http status code func (lrw *ResponseRecorder) WriteHeader(code int) { if !lrw.headersLogged { + lrw.ttfbHeader = time.Now().UTC().Sub(lrw.StartTime) lrw.StatusCode = code lrw.writeHeaders(&lrw.headers, code, lrw.ResponseWriter.Header()) lrw.headersLogged = true diff --git a/internal/logger/audit.go b/internal/logger/audit.go index cd60c6004..cad1df0e5 100644 --- a/internal/logger/audit.go +++ b/internal/logger/audit.go @@ -100,7 +100,7 @@ func AuditLog(ctx context.Context, w http.ResponseWriter, r *http.Request, reqCl outputBytes = int64(tc.ResponseRecorder.Size()) headerBytes = int64(tc.ResponseRecorder.HeaderSize()) timeToResponse = time.Now().UTC().Sub(tc.ResponseRecorder.StartTime) - timeToFirstByte = tc.ResponseRecorder.TimeToFirstByte + timeToFirstByte = tc.ResponseRecorder.TTFB() } entry.AccessKey = reqInfo.Cred.AccessKey