From e12c0414039f7e818e31aa4765a5e69666333069 Mon Sep 17 00:00:00 2001
From: Tom Clegg <tom@curoverse.com>
Date: Tue, 15 Nov 2016 02:42:25 -0500
Subject: [PATCH] 8460: JSON request log.

---
 services/ws/router.go | 24 +++++++++++++++++++-----
 1 file changed, 19 insertions(+), 5 deletions(-)

diff --git a/services/ws/router.go b/services/ws/router.go
index e829ce88d7..69654cbe52 100644
--- a/services/ws/router.go
+++ b/services/ws/router.go
@@ -2,10 +2,10 @@ package main
 
 import (
 	"encoding/json"
-	"fmt"
 	"log"
 	"net/http"
 	"sync"
+	"time"
 
 	"git.curoverse.com/arvados.git/sdk/go/arvados"
 	"golang.org/x/net/websocket"
@@ -37,22 +37,36 @@ func (rtr *router) makeServer(newSession func(wsConn, arvados.Client) (session,
 			return nil
 		},
 		Handler: websocket.Handler(func(ws *websocket.Conn) {
-			log.Printf("%v accepted", ws.Request().RemoteAddr)
 			sink := rtr.eventSource.NewSink()
 			handler.Handle(ws, sink.Channel())
 			sink.Stop()
 			ws.Close()
-			log.Printf("%v disconnected", ws.Request().RemoteAddr)
 		}),
 	}
 }
 
 func (rtr *router) ServeHTTP(resp http.ResponseWriter, req *http.Request) {
 	rtr.setupOnce.Do(rtr.setup)
+	t0 := time.Now()
+	reqLog(map[string]interface{}{
+		"Connect":         req.RemoteAddr,
+		"RemoteAddr":      req.RemoteAddr,
+		"X-Forwarded-For": req.Header.Get("X-Forwarded-For"),
+		"Time":            t0.UTC(),
+	})
 	rtr.mux.ServeHTTP(resp, req)
-	j, err := json.Marshal(map[string]interface{}{
-		"req": fmt.Sprintf("%+v", req),
+	t1 := time.Now()
+	reqLog(map[string]interface{}{
+		"Disconnect":      req.RemoteAddr,
+		"RemoteAddr":      req.RemoteAddr,
+		"X-Forwarded-For": req.Header.Get("X-Forwarded-For"),
+		"Time":            t1.UTC(),
+		"Elapsed":         time.Now().Sub(t0).Seconds(),
 	})
+}
+
+func reqLog(m map[string]interface{}) {
+	j, err := json.Marshal(m)
 	if err != nil {
 		log.Fatal(err)
 	}
-- 
2.30.2