Merge branch '9068-drop-abandoned-conns'

[arvados.git] / services / keepstore / logging_router.go

diff --git a/services/keepstore/logging_router.go b/services/keepstore/logging_router.go
index 47bb6d77179f226dc20d84a525fa5a0de3a5f7af..0f556b538ac7ae15b1939f61bad13be3ed0404e5 100644 (file)
--- a/services/keepstore/logging_router.go
+++ b/services/keepstore/logging_router.go
@@ -4,7 +4,6 @@ package main
 // LoggingResponseWriter
 
 import (
-       "github.com/gorilla/mux"
        "log"
        "net/http"
        "strings"
@@ -17,41 +16,62 @@ type LoggingResponseWriter struct {
        Length int
        http.ResponseWriter
        ResponseBody string
+       sentHdr      time.Time
+}
+
+// CloseNotify implements http.CloseNotifier.
+func (resp *LoggingResponseWriter) CloseNotify() <-chan bool {
+       wrapped, ok := resp.ResponseWriter.(http.CloseNotifier)
+       if !ok {
+               // If upstream doesn't implement CloseNotifier, we can
+               // satisfy the interface by returning a channel that
+               // never sends anything (the interface doesn't
+               // guarantee that anything will ever be sent on the
+               // channel even if the client disconnects).
+               return nil
+       }
+       return wrapped.CloseNotify()
 }
 
 // WriteHeader writes header to ResponseWriter
-func (loggingWriter *LoggingResponseWriter) WriteHeader(code int) {
-       loggingWriter.Status = code
-       loggingWriter.ResponseWriter.WriteHeader(code)
+func (resp *LoggingResponseWriter) WriteHeader(code int) {
+       if resp.sentHdr == zeroTime {
+               resp.sentHdr = time.Now()
+       }
+       resp.Status = code
+       resp.ResponseWriter.WriteHeader(code)
 }
 
-func (loggingWriter *LoggingResponseWriter) Write(data []byte) (int, error) {
-       loggingWriter.Length += len(data)
-       if loggingWriter.Status >= 400 {
-               loggingWriter.ResponseBody += string(data)
+var zeroTime time.Time
+
+func (resp *LoggingResponseWriter) Write(data []byte) (int, error) {
+       if resp.Length == 0 && len(data) > 0 && resp.sentHdr == zeroTime {
+               resp.sentHdr = time.Now()
+       }
+       resp.Length += len(data)
+       if resp.Status >= 400 {
+               resp.ResponseBody += string(data)
        }
-       return loggingWriter.ResponseWriter.Write(data)
+       return resp.ResponseWriter.Write(data)
 }
 
 // LoggingRESTRouter is used to add logging capabilities to mux.Router
 type LoggingRESTRouter struct {
-       router *mux.Router
-}
-
-// MakeLoggingRESTRouter initializes LoggingRESTRouter
-func MakeLoggingRESTRouter() *LoggingRESTRouter {
-       router := MakeRESTRouter()
-       return (&LoggingRESTRouter{router})
+       router http.Handler
 }
 
-func (loggingRouter *LoggingRESTRouter) ServeHTTP(resp http.ResponseWriter, req *http.Request) {
+func (loggingRouter *LoggingRESTRouter) ServeHTTP(wrappedResp http.ResponseWriter, req *http.Request) {
        t0 := time.Now()
-       loggingWriter := LoggingResponseWriter{http.StatusOK, 0, resp, ""}
-       loggingRouter.router.ServeHTTP(&loggingWriter, req)
-       statusText := http.StatusText(loggingWriter.Status)
-       if loggingWriter.Status >= 400 {
-               statusText = strings.Replace(loggingWriter.ResponseBody, "\n", "", -1)
+       resp := LoggingResponseWriter{http.StatusOK, 0, wrappedResp, "", zeroTime}
+       loggingRouter.router.ServeHTTP(&resp, req)
+       statusText := http.StatusText(resp.Status)
+       if resp.Status >= 400 {
+               statusText = strings.Replace(resp.ResponseBody, "\n", "", -1)
        }
-       log.Printf("[%s] %s %s %.6fs %d %d \"%s\"", req.RemoteAddr, req.Method, req.URL.Path[1:], time.Since(t0).Seconds(), loggingWriter.Status, loggingWriter.Length, statusText)
+       now := time.Now()
+       tTotal := now.Sub(t0)
+       tLatency := resp.sentHdr.Sub(t0)
+       tResponse := now.Sub(resp.sentHdr)
+       log.Printf("[%s] %s %s %d %.6fs %.6fs %.6fs %d %d \"%s\"", req.RemoteAddr, req.Method, req.URL.Path[1:], req.ContentLength, tTotal.Seconds(), tLatency.Seconds(), tResponse.Seconds(), resp.Status, resp.Length, statusText)
 
 }