services/keepstore/logging_router.go

   1 package main
   2
   3 // LoggingRESTRouter
   4 // LoggingResponseWriter
   5
   6 import (
   7         "net/http"
   8         "strings"
   9         "time"
  10
  11         "git.curoverse.com/arvados.git/sdk/go/httpserver"
  12         log "github.com/Sirupsen/logrus"
  13 )
  14
  15 // LoggingResponseWriter has anonymous fields ResponseWriter and ResponseBody
  16 type LoggingResponseWriter struct {
  17         Status int
  18         Length int
  19         http.ResponseWriter
  20         ResponseBody string
  21         sentHdr      time.Time
  22 }
  23
  24 // CloseNotify implements http.CloseNotifier.
  25 func (resp *LoggingResponseWriter) CloseNotify() <-chan bool {
  26         wrapped, ok := resp.ResponseWriter.(http.CloseNotifier)
  27         if !ok {
  28                 // If upstream doesn't implement CloseNotifier, we can
  29                 // satisfy the interface by returning a channel that
  30                 // never sends anything (the interface doesn't
  31                 // guarantee that anything will ever be sent on the
  32                 // channel even if the client disconnects).
  33                 return nil
  34         }
  35         return wrapped.CloseNotify()
  36 }
  37
  38 // WriteHeader writes header to ResponseWriter
  39 func (resp *LoggingResponseWriter) WriteHeader(code int) {
  40         if resp.sentHdr == zeroTime {
  41                 resp.sentHdr = time.Now()
  42         }
  43         resp.Status = code
  44         resp.ResponseWriter.WriteHeader(code)
  45 }
  46
  47 var zeroTime time.Time
  48
  49 func (resp *LoggingResponseWriter) Write(data []byte) (int, error) {
  50         if resp.Length == 0 && len(data) > 0 && resp.sentHdr == zeroTime {
  51                 resp.sentHdr = time.Now()
  52         }
  53         resp.Length += len(data)
  54         if resp.Status >= 400 {
  55                 resp.ResponseBody += string(data)
  56         }
  57         return resp.ResponseWriter.Write(data)
  58 }
  59
  60 // LoggingRESTRouter is used to add logging capabilities to mux.Router
  61 type LoggingRESTRouter struct {
  62         router      http.Handler
  63         idGenerator httpserver.IDGenerator
  64 }
  65
  66 func (loggingRouter *LoggingRESTRouter) ServeHTTP(wrappedResp http.ResponseWriter, req *http.Request) {
  67         tStart := time.Now()
  68         lgr := log.WithFields(log.Fields{
  69                 "RequestID":       loggingRouter.idGenerator.Next(),
  70                 "RemoteAddr":      req.RemoteAddr,
  71                 "X-Forwarded-For": req.Header.Get("X-Forwarded-For"),
  72                 "ReqMethod":       req.Method,
  73                 "ReqPath":         req.URL.Path[1:],
  74                 "ReqBytes":        req.ContentLength,
  75         })
  76         lgr.Info("request")
  77
  78         resp := LoggingResponseWriter{http.StatusOK, 0, wrappedResp, "", zeroTime}
  79         loggingRouter.router.ServeHTTP(&resp, req)
  80         statusText := http.StatusText(resp.Status)
  81         if resp.Status >= 400 {
  82                 statusText = strings.Replace(resp.ResponseBody, "\n", "", -1)
  83         }
  84
  85         tDone := time.Now()
  86         lgr.WithFields(log.Fields{
  87                 "TimeTotal":      tDone.Sub(tStart).Seconds(),
  88                 "TimeToStatus":   resp.sentHdr.Sub(tStart).Seconds(),
  89                 "TimeWriteBody":  tDone.Sub(resp.sentHdr).Seconds(),
  90                 "RespStatusCode": resp.Status,
  91                 "RespStatus":     statusText,
  92                 "RespBytes":      resp.Length,
  93         }).Info("response")
  94 }