feat(coderd/httpmw): log start timestamp for http requests (#9776)

mafredri · web-flow · commit 4e442040f736 · 2023-09-27T14:39:22.000+03:00
diff --git a/coderd/httpmw/logger.go b/coderd/httpmw/logger.go
@@ -26,19 +26,28 @@ func Logger(log slog.Logger) func(next http.Handler) http.Handler {
 				slog.F("path", r.URL.Path),
 				slog.F("proto", r.Proto),
 				slog.F("remote_addr", r.RemoteAddr),
+				// Include the start timestamp in the log so that we have the
+				// source of truth. There is at least a theoretical chance that
+				// there can be a delay between `next.ServeHTTP` ending and us
+				// actually logging the request. This can also be useful when
+				// filtering logs that started at a certain time (compared to
+				// trying to compute the value).
+				slog.F("start", start),
 			)
 
 			next.ServeHTTP(sw, r)
 
+			end := time.Now()
+
 			// Don't log successful health check requests.
 			if r.URL.Path == "/api/v2" && sw.Status == http.StatusOK {
 				return
 			}
 
 			httplog = httplog.With(
-				slog.F("took", time.Since(start)),
+				slog.F("took", end.Sub(start)),
 				slog.F("status_code", sw.Status),
-				slog.F("latency_ms", float64(time.Since(start)/time.Millisecond)),
+				slog.F("latency_ms", float64(end.Sub(start)/time.Millisecond)),
 			)
 
 			// For status codes 400 and higher we
